Dear Jacob, I run my PRACH test for a few minutes and the problem popped up. I am attahcing the UE and the PCU side logs.
In the UE log note that the UL TBF is released almost right after the PRACH is finsihed, while the ICMP echo request is being sent (and lost). In the PCU log the interesting part is close to the bottom. One line to highlight: Software error: Pending downlink assignment. This may not happen, because the assignment message never gets transmitted. Please be sure not to free in this state. PLEASE FIX! This message is quite close to the part where the ICMP echo request got lost, but it is hard to tell because to two logs are not synchronised. Will continue testing because this error looks a littlebit different than the one I catched yesterday. Regards, Csaba ----- Eredeti üzenet ----- Feladó: "Sipos Csaba" <[email protected]> Címzett: "Jacob Erlbeck" <[email protected]> Másolatot kap: "OpenBSC Mailing List" <[email protected]> Elküldött üzenetek: Hétfő, 2015. Szeptember 21. 21:10:16 Tárgy: Re: DL TBF abnormal release Dear Jacob, I am using the laster master branch of Osmo-PCU. Last commit: commit 7c8d39a67b7568cda38829c774ea541250f3142f Author: Jacob Erlbeck <[email protected]> Date: Mon Sep 7 14:04:56 2015 +0200 poll: Count failed procedures > The UE side log doesn't help much After I gone through it the second time, thats what I tought too :-) I added the extra log options to the pcu config and now try to reproduce the error. Will try and give you as much details as possible. Regards, Csaba ----- Eredeti üzenet ----- Feladó: "Jacob Erlbeck" <[email protected]> Címzett: "Sipos Csaba" <[email protected]> Másolatot kap: "OpenBSC Mailing List" <[email protected]> Elküldött üzenetek: Hétfő, 2015. Szeptember 21. 12:30:31 Tárgy: Re: DL TBF abnormal release Dear Csaba, which exact PCU version (git SHA stamp) are you using? On 20.09.2015 21:15, Sipos Csaba wrote: > > In the past I wrote a little script to test the PRACH stability of OpenBTS, > which sends a single ping to the gateway address, waits until the session > goes into idle, and then tries again. The goal is to generate as many PRACH > as possible and check if there is a response. > > I used this script and it turns out that around 1 out of every 20 requests > the ping is not reaching the gateway, and the UE indicates an abnormal DL TBF > release. > > I attached the UE side log, so you can take a look. The UE side log doesn't help much, as I cannot see much differences between either case (even the time deltas before each EVENT_GPRS_TBF_RELEASE are similar). It would be very helpful, if I had the logging output of the PCU, e.g. by adding the following stanza to the osmo-pcu.cfg file: ==== log file /tmp/pcu.log logging filter all 1 logging color 0 logging print extended-timestamp 1 logging level all everything logging level rlcmac debug logging level rlcmacul debug logging level rlcmacdl debug logging level l1if info logging level bssgp debug logging level rlcmacdata debug logging level rlcmacmeas debug logging level rlcmacsched debug logging level pcu debug ==== > > During this issue there is no reasonable frequency nor timing variation > indicated on the UE side. > > What I noticed is the very high number of RLC resent and RLC restarted. After > a few minutes of pinging, this is the result from the PCU: > > RLC Sent : 18015 (0/s 0/m 0/h 0/d) > RLC Resent : 17596 (0/s 0/m 0/h 0/d) > RLC Restarted : 15669 (0/s 0/m 0/h 0/d) > RLC Stalled : 0 (0/s 0/m 0/h 0/d) This probably results from the dl-tbf-idle-time feature. When enabled, the DL TBF is not closed after the last LLC frame. Instead the DL TBF is kept open by sending LLC dummy commands at regular intervals. Each of them creates a single RLC packet which is then resent in every free slot with a low priority until the corresponding ACK is received. Note that this rewrapping of the send buffer will not happen, when there is other data to be sent (this is meant by 'low priority'). Regards Jacob -- - Jacob Erlbeck <[email protected]> http://www.sysmocom.de/ ======================================================================= * sysmocom - systems for mobile communications GmbH * Alt-Moabit 93 * 10559 Berlin, Germany * Sitz / Registered office: Berlin, HRB 134158 B * Geschaeftsfuehrer / Managing Directors: Holger Freyther, Harald Welte
EVENT_GSM_L1_STATE 19:28:26.741 L1_IDLE_MODE EVENT_GSM_L1_STATE 19:28:28.271 L1_RANDOM_ACCESS_MODE EVENT_RANDOM_ACCESS_REQUEST 19:28:28.280 1 31537 GMAC_ONE_PHASE_ACCESS EVENT_GSM_MESSAGE_RECEIVED 19:28:28.474 IMMEDIATE_ASSIGNMENT EVENT_GPRS_MAC_MSG_SENT 19:28:28.475 Message: Packet Uplink Dummy Control Block Channel: 0 EVENT_GSM_L1_STATE 19:28:28.488 L1_TRANSFER_MODE EVENT_GPRS_MAC_MSG_RECEIVED 19:28:28.732 Message: Packet Uplink Ack/Nack Channel: 0 EVENT_GPRS_MAC_MSG_SENT 19:28:28.732 Message: Packet Control Acknowledgement Channel: 0 EVENT_GPRS_TBF_RELEASE 19:28:28.732 TBF Release Type: UL_TBF_NORMAL EVENT_GSM_L1_STATE 19:28:28.824 L1_IDLE_MODE EVENT_GSM_L1_STATE 19:28:38.102 L1_RANDOM_ACCESS_MODE EVENT_RANDOM_ACCESS_REQUEST 19:28:38.143 1 33674 GMAC_ONE_PHASE_ACCESS EVENT_GSM_MESSAGE_RECEIVED 19:28:38.342 ALERTING EVENT_GSM_MESSAGE_RECEIVED 19:28:38.360 IMMEDIATE_ASSIGNMENT EVENT_GPRS_MAC_MSG_SENT 19:28:38.361 Message: Packet Uplink Dummy Control Block Channel: 0 EVENT_GSM_L1_STATE 19:28:38.370 L1_TRANSFER_MODE EVENT_GPRS_MAC_MSG_RECEIVED 19:28:38.591 Message: Packet Uplink Ack/Nack Channel: 0 EVENT_GPRS_MAC_MSG_RECEIVED 19:28:38.608 Message: Packet Downlink Assignment Channel: 0 EVENT_GPRS_PACKET_DOWNLINK_ASSIGNMENT19:28:38.609 Time Slot Allocation: 15, TFI Assignment: 0 EVENT_GPRS_MAC_MSG_SENT 19:28:38.609 Message: Packet Control Acknowledgement Channel: 0 EVENT_GPRS_MAC_MSG_RECEIVED 19:28:38.829 Message: Packet Uplink Ack/Nack Channel: 0 EVENT_GPRS_MAC_MSG_SENT 19:28:38.829 Message: Packet Control Acknowledgement Channel: 0 EVENT_GPRS_TBF_RELEASE 19:28:38.829 TBF Release Type: UL_TBF_NORMAL EVENT_GPRS_MAC_MSG_SENT 19:28:38.852 Message: Packet Downlink Ack/Nack Channel: 0 EVENT_GPRS_MAC_MSG_SENT 19:28:39.074 Message: Packet Downlink Ack/Nack Channel: 0 EVENT_GPRS_MAC_MSG_SENT 19:28:39.295 Message: Packet Downlink Ack/Nack Channel: 0 EVENT_GPRS_MAC_MSG_SENT 19:28:39.535 Message: Packet Downlink Ack/Nack Channel: 0 EVENT_GPRS_MAC_MSG_SENT 19:28:39.775 Message: Packet Downlink Ack/Nack Channel: 0 EVENT_GPRS_MAC_MSG_SENT 19:28:39.992 Message: Packet Downlink Ack/Nack Channel: 0 EVENT_GPRS_MAC_MSG_SENT 19:28:40.214 Message: Packet Downlink Ack/Nack Channel: 0 EVENT_GPRS_MAC_MSG_SENT 19:28:40.435 Message: Packet Downlink Ack/Nack Channel: 0 EVENT_GPRS_MAC_MSG_SENT 19:28:40.652 Message: Packet Downlink Ack/Nack Channel: 0 EVENT_GPRS_MAC_MSG_SENT 19:28:40.874 Message: Packet Downlink Ack/Nack Channel: 0 EVENT_GPRS_MAC_MSG_SENT 19:28:41.095 Message: Packet Downlink Ack/Nack Channel: 0 EVENT_GPRS_MAC_MSG_SENT 19:28:41.312 Message: Packet Downlink Ack/Nack Channel: 0 EVENT_GPRS_MAC_MSG_SENT 19:28:41.534 Message: Packet Downlink Ack/Nack Channel: 0 EVENT_GPRS_MAC_MSG_SENT 19:28:41.755 Message: Packet Downlink Ack/Nack Channel: 0 EVENT_GPRS_MAC_MSG_SENT 19:28:41.972 Message: Packet Downlink Ack/Nack Channel: 0 EVENT_GPRS_MAC_MSG_SENT 19:28:42.194 Message: Packet Downlink Ack/Nack Channel: 0 EVENT_GPRS_MAC_MSG_SENT 19:28:42.415 Message: Packet Downlink Ack/Nack Channel: 0 EVENT_GPRS_MAC_MSG_SENT 19:28:42.632 Message: Packet Downlink Ack/Nack Channel: 0 EVENT_GPRS_MAC_MSG_SENT 19:28:42.854 Message: Packet Downlink Ack/Nack Channel: 0 EVENT_GPRS_TBF_RELEASE 19:28:44.381 TBF Release Type: DL_TBF_NORMAL EVENT_GSM_L1_STATE 19:28:44.400 L1_IDLE_MODE
<<attachment: pcu.zip>>
