Re[2]: Abis RSL and channel allocation issue

Hello Holger, Of cause it was established. Here is a complete log of the situation with SMS: Tue Oct 29 21:21:40 2013 <001e> sms_queue.c:220 Attempting to send 20 SMS Tue Oct 29 21:21:42 2013 <0004> abis_rsl.c:1467 (bts=0,trx=0,ts=0,ss=0) Activating ARFCN(885) SS(0) lctype SDCCH r=LOCATION_UPDATE ra=0x16 ta=0 Tue Oct 29 21:21:42 2013 <0004> abis_rsl.c:1169 (bts=0,trx=0,ts=0,ss=0) CHANNEL ACTIVATE ACK Tue Oct 29 21:21:42 2013 <0000> abis_rsl.c:1657 (bts=0,trx=0,ts=0,ss=0) SAPI=0 ESTABLISH INDICATION Tue Oct 29 21:21:42 2013 <0003> gsm_04_08.c:1187 PAGING RESPONSE: mi_type=0x04 MI(2040770818) Tue Oct 29 21:21:42 2013 <0003> gsm_04_08.c:1205 <- Channel was requested by 244153333330127 Tue Oct 29 21:21:42 2013 <0001> transaction.c:69 subscr=0x9ad51f0, subscr->net=0x9a90248 Tue Oct 29 21:21:42 2013 <0000> abis_rsl.c:866 (bts=0,trx=0,ts=0,ss=0) RSL RLL ESTABLISH REQ (link_id=0x03) Tue Oct 29 21:21:42 2013 <0000> abis_rsl.c:1657 (bts=0,trx=0,ts=0,ss=0) SAPI=0 DATA INDICATION Tue Oct 29 21:21:42 2013 <0003> bsc_api.c:615 CLASSMARK CHANGE CM2(len=3) CM3(len=9) Tue Oct 29 21:21:42 2013 <001a> input/dahdi.c:320 send returns -1 instead of 160 Tue Oct 29 21:21:42 2013 <001a> input/dahdi.c:320 send returns -1 instead of 160 Tue Oct 29 21:21:43 2013 <0000> abis_rsl.c:1657 (bts=0,trx=0,ts=0,ss=0) SAPI=3 ESTABLISH CONFIRM Tue Oct 29 21:21:44 2013 <0000> abis_rsl.c:1657 (bts=0,trx=0,ts=0,ss=0) SAPI=3 DATA INDICATION Tue Oct 29 21:21:44 2013 <0000> abis_rsl.c:1657 (bts=0,trx=0,ts=0,ss=0) SAPI=3 DATA INDICATION Tue Oct 29 21:21:45 2013 <001e> sms_queue.c:220 Attempting to send 20 SMS Tue Oct 29 21:21:45 2013 <0000> chan_alloc.c:457 (bts=0,trx=0,ts=0,ss=0) starting release sequence Tue Oct 29 21:21:45 2013 <0000> abis_rsl.c:892 (bts=0,trx=0,ts=0,ss=0) RSL RLL RELEASE REQ (link_id=0x03, reason=1) Tue Oct 29 21:21:45 2013 <0003> gsm_04_08_utils.c:231 Sending Channel Release: Chan: Number: 0 Type: 1 Tue Oct 29 21:21:45 2013 <0004> abis_rsl.c:634 (bts=0,trx=0,ts=0,ss=0) DEACTivate SACCH CMD Tue Oct 29 21:21:45 2013 <0004> abis_rsl.c:1070 (bts=0,trx=0,ts=0,ss=0): MEAS RES for inactive channel Tue Oct 29 21:21:45 2013 <001a> input/dahdi.c:320 send returns -1 instead of 160 Tue Oct 29 21:21:45 2013 <001a> input/dahdi.c:320 send returns -1 instead of 160 Tue Oct 29 21:21:45 2013 <0000> abis_rsl.c:1657 (bts=0,trx=0,ts=0,ss=0) SAPI=0 RELEASE INDICATION Tue Oct 29 21:21:45 2013 <0004> abis_rsl.c:1628 (bts=0,trx=0,ts=0,ss=0) waiting for SAPI=3 to be released. Tue Oct 29 21:21:51 2013 <0000> abis_rsl.c:1657 (bts=0,trx=0,ts=0,ss=0) SAPI=3 Tue Oct 29 21:21:51 2013 <0000> abis_rsl.c:1599 (bts=0,trx=0,ts=0,ss=0) ERROR INDICATION cause=Timer T200 expired (N200+1) times Tue Oct 29 21:21:51 2013 <0004> abis_rsl.c:680 (bts=0,trx=0,ts=0,ss=0) RF Channel Release CMD due error 1 Tue Oct 29 21:21:51 2013 <0004> abis_rsl.c:634 (bts=0,trx=0,ts=0,ss=0) DEACTivate SACCH CMD Tue Oct 29 21:21:51 2013 <0000> abis_rsl.c:892 (bts=0,trx=0,ts=0,ss=0) RSL RLL RELEASE REQ (link_id=0x03, reason=1) Tue Oct 29 21:21:51 2013 <0004> abis_rsl.c:732 (bts=0,trx=0,ts=0,ss=0) RF CHANNEL RELEASE ACK Tue Oct 29 21:21:53 2013 <0004> abis_rsl.c:649 (bts=0,trx=0,ts=0,ss=0) is back in operation. Yes, it was 0, I raised it to 10, but it doesn't change anything, all the problems still exists. Should I try and change other timers too? You mean the local end release being broken in the BTS? How can I find this out? I see your point, that the release command has been sent, but we never got any ACK or something like that back. But how is it possible that it works for SAPI=0 and it does not for SAPI=3 ? These units were used by big organizations to improve the indoor coverage, I really don't think that the BTS or its firmware is wrong by design. Maybe OpenBSC destroys SAPI=0 too fast, and there is not enough time for this: <0000> abis_rsl.c:892 (bts=0,trx=0,ts=0,ss=0) RSL RLL RELEASE REQ (link_id=0x03, reason=1) to be ACKed by the BTS? Here is another log from the failing handover initiated by the Openbsc VTY "handover" command. THe handover is failing even if I move the phone within the same TRX to another channel: Silent call for the MS started (SDCCH): Tue Oct 29 21:28:37 2013 <0004> abis_rsl.c:1467 (bts=0,trx=0,ts=0,ss=0) Activating ARFCN(885) SS(0) lctype SDCCH r=LOCATION_UPDATE ra=0x1f ta=0 Tue Oct 29 21:28:37 2013 <0004> abis_rsl.c:1169 (bts=0,trx=0,ts=0,ss=0) CHANNEL ACTIVATE ACK Tue Oct 29 21:28:38 2013 <0000> abis_rsl.c:1657 (bts=0,trx=0,ts=0,ss=0) SAPI=0 ESTABLISH INDICATION Tue Oct 29 21:28:38 2013 <0003> gsm_04_08.c:1187 PAGING RESPONSE: mi_type=0x04 MI(2040680933) Tue Oct 29 21:28:38 2013 <0003> gsm_04_08.c:1205 <- Channel was requested by 244153333330127 Tue Oct 29 21:28:38 2013 <0000> abis_rsl.c:1657 (bts=0,trx=0,ts=0,ss=0) SAPI=0 DATA INDICATION Tue Oct 29 21:28:38 2013 <0003> bsc_api.c:615 CLASSMARK CHANGE CM2(len=3) CM3(len=9) The handover command given in Openbsc VTY (% Handover started from (bts=0,trx=0,ts=0,ss=0) to (bts=0,trx=0,ts=2,ss=0): Tue Oct 29 21:28:50 2013 <000c> handover_logic.c:66 (BTS 0 (subscr 244153333330127)) Start Handover Tue Oct 29 21:28:50 2013 <0004> abis_rsl.c:1169 (bts=0,trx=0,ts=2,ss=0) CHANNEL ACTIVATE ACK Tue Oct 29 21:28:50 2013 <000c> handover_logic.c:66 (BTS 0 (subscr 244153333330127)) Channel activate ack, send HO/AS Command Tue Oct 29 21:28:51 2013 <0004> abis_rsl.c:1142 (bts=0,trx=0,ts=2,ss=0) HANDOVER DETECT access delay = 0 Tue Oct 29 21:28:51 2013 <000c> handover_logic.c:66 (BTS 0 (subscr 244153333330127)) Handover RACH detected Tue Oct 29 21:28:51 2013 <0000> abis_rsl.c:1657 (bts=0,trx=0,ts=2,ss=0) SAPI=0 ESTABLISH INDICATION Tue Oct 29 21:28:51 2013 <0000> abis_rsl.c:1657 (bts=0,trx=0,ts=2,ss=0) SAPI=0 DATA INDICATION Tue Oct 29 21:28:51 2013 <0003> bsc_api.c:651 HANDOVER COMPLETE cause = Normal event Tue Oct 29 21:28:51 2013 <000c> handover_logic.c:66 (BTS 0 (subscr 244153333330127)) Handover/Assignment completed Handover success from BSC point of view, but we have to close the old chan first: Tue Oct 29 21:28:51 2013 <0000> chan_alloc.c:457 (bts=0,trx=0,ts=0,ss=0) starting release sequence Tue Oct 29 21:28:51 2013 <0000> abis_rsl.c:892 (bts=0,trx=0,ts=0,ss=0) RSL RLL RELEASE REQ (link_id=0x00, reason=1) Tue Oct 29 21:28:51 2013 <0004> abis_rsl.c:1070 (bts=0,trx=0,ts=0,ss=0): MEAS RES for inactive channel ............................... Tue Oct 29 21:29:20 2013 <0004> abis_rsl.c:1070 (bts=0,trx=0,ts=0,ss=0): MEAS RES for inactive channel Which is not happening despite we given the command, and times out after "radio-link-timeout 16": Tue Oct 29 21:29:20 2013 <0004> abis_rsl.c:989 (bts=0,trx=0,ts=0,ss=0) CONNECTION FAIL: RELEASING CAUSE=0x01(Radio Link Failure) Tue Oct 29 21:29:20 2013 <0004> abis_rsl.c:680 (bts=0,trx=0,ts=0,ss=0) RF Channel Release CMD due error 1 Tue Oct 29 21:29:20 2013 <0004> abis_rsl.c:634 (bts=0,trx=0,ts=0,ss=0) DEACTivate SACCH CMD Tue Oct 29 21:29:20 2013 <0000> abis_rsl.c:892 (bts=0,trx=0,ts=0,ss=0) RSL RLL RELEASE REQ (link_id=0x00, reason=1) Tue Oct 29 21:29:20 2013 <0004> abis_rsl.c:1070 (bts=0,trx=0,ts=0,ss=0): MEAS RES for inactive channel Tue Oct 29 21:29:20 2013 <0004> abis_rsl.c:732 (bts=0,trx=0,ts=0,ss=0) RF CHANNEL RELEASE ACK Tue Oct 29 21:29:22 2013 <0004> abis_rsl.c:649 (bts=0,trx=0,ts=0,ss=0) is back in operation. The slient call is still working on the new channel, so I gave command to close it (silent-call stop): Tue Oct 29 21:29:49 2013 <0000> chan_alloc.c:457 (bts=0,trx=0,ts=2,ss=0) starting release sequence Tue Oct 29 21:29:49 2013 <0003> gsm_04_08_utils.c:231 Sending Channel Release: Chan: Number: 0 Type: 2 Tue Oct 29 21:29:49 2013 <0004> abis_rsl.c:634 (bts=0,trx=0,ts=2,ss=0) DEACTivate SACCH CMD Tue Oct 29 21:29:49 2013 <0004> abis_rsl.c:1070 (bts=0,trx=0,ts=2,ss=0): MEAS RES for inactive channel Tue Oct 29 21:29:49 2013 <0000> abis_rsl.c:1657 (bts=0,trx=0,ts=2,ss=0) SAPI=0 RELEASE INDICATION Tue Oct 29 21:29:49 2013 <0004> abis_rsl.c:680 (bts=0,trx=0,ts=2,ss=0) RF Channel Release CMD due error 0 Tue Oct 29 21:29:49 2013 <0004> abis_rsl.c:732 (bts=0,trx=0,ts=2,ss=0) RF CHANNEL RELEASE ACK I hope someone can help me with this. I think we are close to solve this problem. BR, Csaba