1 files changed, 184 insertions, 191 deletions

diff --git a/src/osmo-bts-sysmo/oml.c b/src/osmo-bts-sysmo/oml.c
index ea7527dd..b4f6752d 100644
--- a/src/osmo-bts-sysmo/oml.c
+++ b/src/osmo-bts-sysmo/oml.c
@@ -11,7 +11,7 @@
  * This program is distributed in the hope that it will be useful,
  * but WITHOUT ANY WARRANTY; without even the implied warranty of
  * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
- * GNU General Public License for more details.
+ * GNU Affero General Public License for more details.
  *
  * You should have received a copy of the GNU Affero General Public License
  * along with this program.  If not, see <http://www.gnu.org/licenses/>.
@@ -23,6 +23,7 @@
 
 #include <osmocom/core/talloc.h>
 #include <osmocom/core/utils.h>
+#include <osmocom/core/fsm.h>
 
 #include <sysmocom/femtobts/gsml1prim.h>
 #include <sysmocom/femtobts/gsml1const.h>
@@ -39,11 +40,14 @@
 #include <osmo-bts/phy_link.h>
 #include <osmo-bts/handover.h>
 #include <osmo-bts/l1sap.h>
+#include <osmo-bts/nm_common_fsm.h>
 
 #include "l1_if.h"
 #include "femtobts.h"
 #include "utils.h"
 
+static void dump_lch_par(int logl, GsmL1_LogChParam_t *lch_par, GsmL1_Sapi_t sapi);
+
 static int mph_info_chan_confirm(struct gsm_lchan *lchan,
 			enum osmo_mph_info_type type, uint8_t cause)
 {
@@ -88,13 +92,13 @@ static const enum GsmL1_LogChComb_t pchan_to_logChComb[_GSM_PCHAN_MAX] = {
 	[GSM_PCHAN_PDCH]		= GsmL1_LogChComb_XIII,
 	[GSM_PCHAN_UNKNOWN]		= GsmL1_LogChComb_0,
 	/*
-	 * GSM_PCHAN_TCH_F_PDCH and GSM_PCHAN_TCH_F_TCH_H_PDCH should not be
+	 * GSM_PCHAN_TCH_F_PDCH and GSM_PCHAN_OSMO_DYN should not be
 	 * part of this, only "real" pchan values will be looked up here.
 	 * See the callers of ts_connect_as().
 	 */
 };
 
-static int trx_rf_lock(struct gsm_bts_trx *trx, int locked, l1if_compl_cb *cb);
+int trx_rf_lock(struct gsm_bts_trx *trx, int locked, l1if_compl_cb *cb);
 
 static void *prim_init(GsmL1_Prim_t *prim, GsmL1_PrimId_t id, struct femtol1_hdl *gl1,
 		       HANDLE hLayer3)
@@ -267,36 +271,48 @@ static int opstart_compl(struct gsm_abis_mo *mo, struct msgb *l1_msg)
 {
 	GsmL1_Prim_t *l1p = msgb_l1prim(l1_msg);
 	GsmL1_Status_t status = prim_status(l1p);
+	struct gsm_bts_trx *trx = gsm_bts_trx_num(mo->bts, mo->obj_inst.trx_nr);
 
 	if (status != GsmL1_Status_Success) {
 		LOGP(DL1C, LOGL_ERROR, "Rx %s, status: %s\n",
 			get_value_string(femtobts_l1prim_names, l1p->id),
 			get_value_string(femtobts_l1status_names, status));
 		msgb_free(l1_msg);
-		return oml_mo_opstart_nack(mo, NM_NACK_CANT_PERFORM);
+		switch (mo->obj_class) {
+		case NM_OC_RADIO_CARRIER:
+			return osmo_fsm_inst_dispatch(trx->mo.fi, NM_EV_OPSTART_NACK,
+						      (void*)(intptr_t)NM_NACK_CANT_PERFORM);
+		case NM_OC_CHANNEL:
+			return osmo_fsm_inst_dispatch(trx->ts[mo->obj_inst.ts_nr].mo.fi, NM_EV_OPSTART_NACK,
+						      (void*)(intptr_t)NM_NACK_CANT_PERFORM);
+		default:
+			OSMO_ASSERT(0);
+		}
 	}
 
 	msgb_free(l1_msg);
-
-	/* Set to Operational State: Enabled */
-	oml_mo_state_chg(mo, NM_OPSTATE_ENABLED, NM_AVSTATE_OK);
-
-	/* ugly hack to auto-activate all SAPIs for the BCCH/CCCH on TS0 */
-	if (mo->obj_class == NM_OC_CHANNEL && mo->obj_inst.trx_nr == 0 &&
-	    mo->obj_inst.ts_nr == 0) {
-		struct gsm_lchan *cbch = gsm_bts_get_cbch(mo->bts);
-		DEBUGP(DL1C, "====> trying to activate lchans of BCCH\n");
-		mo->bts->c0->ts[0].lchan[CCCH_LCHAN].rel_act_kind =
-			LCHAN_REL_ACT_OML;
-		lchan_activate(&mo->bts->c0->ts[0].lchan[CCCH_LCHAN]);
-		if (cbch) {
-			cbch->rel_act_kind = LCHAN_REL_ACT_OML;
-			lchan_activate(cbch);
+	switch (mo->obj_class) {
+	case NM_OC_RADIO_CARRIER:
+		return osmo_fsm_inst_dispatch(trx->mo.fi, NM_EV_OPSTART_ACK, NULL);
+	case NM_OC_CHANNEL:
+		/* ugly hack to auto-activate all SAPIs for the BCCH/CCCH on TS0 */
+		if (mo->obj_inst.trx_nr == 0 &&
+		    mo->obj_inst.ts_nr == 0) {
+			struct gsm_lchan *cbch = gsm_bts_get_cbch(mo->bts);
+			DEBUGP(DL1C, "====> trying to activate lchans of BCCH\n");
+			mo->bts->c0->ts[0].lchan[CCCH_LCHAN].rel_act_kind =
+				LCHAN_REL_ACT_OML;
+			lchan_activate(&mo->bts->c0->ts[0].lchan[CCCH_LCHAN]);
+			if (cbch) {
+				cbch->rel_act_kind = LCHAN_REL_ACT_OML;
+				lchan_activate(cbch);
+			}
 		}
+		return osmo_fsm_inst_dispatch(trx->ts[mo->obj_inst.ts_nr].mo.fi,
+					      NM_EV_OPSTART_ACK, NULL);
+	default:
+		OSMO_ASSERT(0);
 	}
-
-	/* Send OPSTART ack */
-	return oml_mo_opstart_ack(mo);
 }
 
 static int opstart_compl_cb(struct gsm_bts_trx *trx, struct msgb *l1_msg,
@@ -325,6 +341,8 @@ static int trx_mute_on_init_cb(struct gsm_bts_trx *trx, struct msgb *resp,
 		bts_shutdown(trx->bts, "RF-MUTE failure");
 	}
 
+	bts_update_status(BTS_STATUS_RF_MUTE, 1);
+
 	msgb_free(resp);
 
 	return 0;
@@ -358,7 +376,7 @@ static int trx_init_compl_cb(struct gsm_bts_trx *trx, struct msgb *l1_msg,
 #endif
 
 	/* Begin to ramp up the power */
-	power_ramp_start(trx, get_p_target_mdBm(trx, 0), 0);
+	power_ramp_start(trx, get_p_target_mdBm(trx, 0), 0, NULL);
 
 	return opstart_compl(&trx->mo, l1_msg);
 }
@@ -394,8 +412,9 @@ static int trx_init(struct gsm_bts_trx *trx)
 				    ARRAY_SIZE(trx_rqd_attr))) {
 		/* HACK: spec says we need to decline, but openbsc
 		 * doesn't deal with this very well */
-		return oml_mo_opstart_ack(&trx->mo);
-		//return oml_mo_opstart_nack(&trx->mo, NM_NACK_CANT_PERFORM);
+		return osmo_fsm_inst_dispatch(trx->mo.fi, NM_EV_OPSTART_ACK, NULL);
+		//return osmo_fsm_inst_dispatch(trx->mo.fi, NM_EV_OPSTART_NACK,
+		//				(void*)(intptr_t)NM_NACK_CANT_PERFORM);
 	}
 
 	femto_band = sysmobts_select_femto_band(trx, trx->arfcn);
@@ -412,9 +431,16 @@ static int trx_init(struct gsm_bts_trx *trx)
 	dev_par->freqBand = femto_band;
 	dev_par->u16Arfcn = trx->arfcn;
 	dev_par->u16BcchArfcn = trx->bts->c0->arfcn;
-	dev_par->u8NbTsc = trx->bts->bsic & 7;
-	dev_par->fRxPowerLevel = trx_ms_pwr_ctrl_is_osmo(trx)
-					? 0.0 : trx->bts->ul_power_target;
+	dev_par->u8NbTsc = BTS_TSC(trx->bts);
+
+	if (!trx_ms_pwr_ctrl_is_osmo(trx)) {
+		/* Target is in the middle between lower and upper RxLev thresholds */
+		int lower_dbm = rxlev2dbm(trx->ms_dpc_params->rxlev_meas.lower_thresh);
+		int upper_dbm = rxlev2dbm(trx->ms_dpc_params->rxlev_meas.upper_thresh);
+		dev_par->fRxPowerLevel = (float) (lower_dbm + upper_dbm) / 2;
+	} else {
+		dev_par->fRxPowerLevel = 0.0;
+	}
 
 	dev_par->fTxPowerLevel = ((float) initial_mdBm) / 1000;
 	LOGP(DL1C, LOGL_NOTICE, "Init TRX (ARFCN %u, TSC %u, RxPower % 2f dBm, "
@@ -426,9 +452,9 @@ static int trx_init(struct gsm_bts_trx *trx)
 	return l1if_gsm_req_compl(fl1h, msg, trx_init_compl_cb, NULL);
 }
 
-uint32_t trx_get_hlayer1(struct gsm_bts_trx *trx)
+uint32_t trx_get_hlayer1(const struct gsm_bts_trx *trx)
 {
-	struct femtol1_hdl *fl1h = trx_femtol1_hdl(trx);
+	const struct femtol1_hdl *fl1h = trx_femtol1_hdl(trx);
 
 	return fl1h->hLayer1;
 }
@@ -437,23 +463,27 @@ static int trx_close_compl_cb(struct gsm_bts_trx *trx, struct msgb *l1_msg,
 			      void *data)
 {
 	msgb_free(l1_msg);
+	bts_model_trx_close_cb(trx, 0);
 	return 0;
 }
 
-int bts_model_trx_close(struct gsm_bts_trx *trx)
+void bts_model_trx_close(struct gsm_bts_trx *trx)
 {
 	struct femtol1_hdl *fl1h = trx_femtol1_hdl(trx);
 	struct msgb *msg;
+	int rc;
 
 	msg = l1p_msgb_alloc();
 	prim_init(msgb_l1prim(msg), GsmL1_PrimId_MphCloseReq, fl1h,
 		  l1p_handle_for_trx(trx));
 	LOGP(DL1C, LOGL_NOTICE, "Close TRX %u\n", trx->nr);
 
-	return l1if_gsm_req_compl(fl1h, msg, trx_close_compl_cb, NULL);
+	rc = l1if_gsm_req_compl(fl1h, msg, trx_close_compl_cb, NULL);
+	if (rc < 0)
+		bts_model_trx_close_cb(trx, rc);
 }
 
-static int trx_rf_lock(struct gsm_bts_trx *trx, int locked, l1if_compl_cb *cb)
+int trx_rf_lock(struct gsm_bts_trx *trx, int locked, l1if_compl_cb *cb)
 {
 	struct femtol1_hdl *fl1h = trx_femtol1_hdl(trx);
 	uint8_t mute[8];
@@ -495,7 +525,7 @@ static int ts_connect_as(struct gsm_bts_trx_ts *ts,
 	GsmL1_MphConnectReq_t *cr;
 
 	if (pchan == GSM_PCHAN_TCH_F_PDCH
-	    || pchan == GSM_PCHAN_TCH_F_TCH_H_PDCH) {
+	    || pchan == GSM_PCHAN_OSMO_DYN) {
 		LOGP(DL1C, LOGL_ERROR,
 		     "%s Requested TS connect as %s,"
 		     " expected a specific pchan instead\n",
@@ -508,10 +538,9 @@ static int ts_connect_as(struct gsm_bts_trx_ts *ts,
 	cr->u8Tn = ts->nr;
 	cr->logChComb = pchan_to_logChComb[pchan];
 
-	DEBUGP(DL1C, "%s pchan=%s ts_connect_as(%s) logChComb=%s\n",
-	       gsm_lchan_name(ts->lchan), gsm_pchan_name(ts->pchan),
-	       gsm_pchan_name(pchan), get_value_string(femtobts_chcomb_names,
-						       cr->logChComb));
+	LOGPLCHAN(ts->lchan, DL1C, LOGL_DEBUG, "pchan=%s ts_connect_as(%s) logChComb=%s\n",
+		    gsm_pchan_name(ts->pchan), gsm_pchan_name(pchan),
+		    get_value_string(femtobts_chcomb_names, cr->logChComb));
 
 	return l1if_gsm_req_compl(fl1h, msg, cb, NULL);
 }
@@ -520,7 +549,7 @@ static int ts_opstart(struct gsm_bts_trx_ts *ts)
 {
 	enum gsm_phys_chan_config pchan = ts->pchan;
 	switch (pchan) {
-	case GSM_PCHAN_TCH_F_TCH_H_PDCH:
+	case GSM_PCHAN_OSMO_DYN:
 		ts->dyn.pchan_is = ts->dyn.pchan_want = GSM_PCHAN_NONE;
 		/* First connect as NONE, until first RSL CHAN ACT. */
 		pchan = GSM_PCHAN_NONE;
@@ -544,8 +573,7 @@ GsmL1_Sapi_t lchan_to_GsmL1_Sapi_t(const struct gsm_lchan *lchan)
 	case GSM_LCHAN_TCH_H:
 		return GsmL1_Sapi_TchH;
 	default:
-		LOGP(DL1C, LOGL_NOTICE, "%s cannot determine L1 SAPI\n",
-			gsm_lchan_name(lchan));
+		LOGPLCHAN(lchan, DL1C, LOGL_NOTICE, "cannot determine L1 SAPI\n");
 		break;
 	}
 	return GsmL1_Sapi_Idle;
@@ -555,7 +583,7 @@ GsmL1_SubCh_t lchan_to_GsmL1_SubCh_t(const struct gsm_lchan *lchan)
 {
 	enum gsm_phys_chan_config pchan = lchan->ts->pchan;
 
-	if (pchan == GSM_PCHAN_TCH_F_TCH_H_PDCH)
+	if (pchan == GSM_PCHAN_OSMO_DYN)
 		pchan = lchan->ts->dyn.pchan_want;
 
 	switch (pchan) {
@@ -575,7 +603,7 @@ GsmL1_SubCh_t lchan_to_GsmL1_SubCh_t(const struct gsm_lchan *lchan)
 	case GSM_PCHAN_TCH_F_PDCH:
 	case GSM_PCHAN_UNKNOWN:
 	default:
-	/* case GSM_PCHAN_TCH_F_TCH_H_PDCH: is caught above */
+	/* case GSM_PCHAN_OSMO_DYN: is caught above */
 		return GsmL1_SubCh_NA;
 	}
 
@@ -638,10 +666,6 @@ static const struct sapi_dir pdtch_sapis[] = {
 #endif
 };
 
-static const struct sapi_dir ho_sapis[] = {
-	{ GsmL1_Sapi_Rach,	GsmL1_Dir_RxUplink },
-};
-
 struct lchan_sapis {
 	const struct sapi_dir *sapis;
 	unsigned int num_sapis;
@@ -674,11 +698,6 @@ static const struct lchan_sapis sapis_for_lchan[_GSM_LCHAN_MAX] = {
 	},
 };
 
-static const struct lchan_sapis sapis_for_ho = {
-	.sapis = ho_sapis,
-	.num_sapis = ARRAY_SIZE(ho_sapis),
-};
-
 static int mph_send_activate_req(struct gsm_lchan *lchan, struct sapi_cmd *cmd);
 static int mph_send_deactivate_req(struct gsm_lchan *lchan, struct sapi_cmd *cmd);
 static int mph_send_config_ciphering(struct gsm_lchan *lchan, struct sapi_cmd *cmd);
@@ -766,12 +785,8 @@ static void sapi_queue_dispatch(struct gsm_lchan *lchan, int status)
 	talloc_free(cmd);
 
 	if (end || llist_empty(&lchan->sapi_cmds)) {
-		LOGP(DL1C, LOGL_DEBUG,
-			"%s End of SAPI cmd queue encountered.%s\n",
-			gsm_lchan_name(lchan),
-			llist_empty(&lchan->sapi_cmds)
-				? " Queue is now empty."
-				: " More pending.");
+		LOGPLCHAN(lchan, DL1C, LOGL_DEBUG, "End of SAPI cmd queue encountered.%s\n",
+			  llist_empty(&lchan->sapi_cmds) ? " Queue is now empty." : " More pending.");
 		return;
 	}
 
@@ -811,8 +826,7 @@ static int lchan_act_compl_cb(struct gsm_bts_trx *trx, struct msgb *l1_msg,
 		goto err;
 	}
 
-	LOGP(DL1C, LOGL_INFO, "%s MPH-ACTIVATE.conf (%s ",
-		gsm_lchan_name(lchan),
+	LOGPLCHAN(lchan, DL1C, LOGL_INFO, "MPH-ACTIVATE.conf (%s ",
 		get_value_string(femtobts_l1sapi_names, ic->sapi));
 	LOGPC(DL1C, LOGL_INFO, "%s)\n",
 		get_value_string(femtobts_dir_names, ic->dir));
@@ -834,19 +848,15 @@ static int lchan_act_compl_cb(struct gsm_bts_trx *trx, struct msgb *l1_msg,
 		lchan->sapis_ul[ic->sapi] = status;
 
 	if (llist_empty(&lchan->sapi_cmds)) {
-		LOGP(DL1C, LOGL_ERROR,
-				"%s Got activation confirmation with empty queue\n",
-				gsm_lchan_name(lchan));
+		LOGPLCHAN(lchan, DL1C, LOGL_ERROR, "Got activation confirmation with empty queue\n");
 		goto err;
 	}
 
 	cmd = llist_entry(lchan->sapi_cmds.next, struct sapi_cmd, entry);
 	if (cmd->sapi != ic->sapi || cmd->dir != ic->dir ||
 			cmd->type != SAPI_CMD_ACTIVATE) {
-		LOGP(DL1C, LOGL_ERROR,
-				"%s Confirmation mismatch (%d, %d) (%d, %d)\n",
-				gsm_lchan_name(lchan), cmd->sapi, cmd->dir,
-				ic->sapi, ic->dir);
+		LOGPLCHAN(lchan, DL1C, LOGL_ERROR, "Confirmation mismatch (%d, %d) (%d, %d)\n",
+			  cmd->sapi, cmd->dir, ic->sapi, ic->dir);
 		goto err;
 	}
 
@@ -926,15 +936,14 @@ static void set_payload_format(GsmL1_LogChParam_t *lch_par)
 #endif /* L1_HAS_RTP_MODE */
 }
 
-static void lchan2lch_par(GsmL1_LogChParam_t *lch_par, struct gsm_lchan *lchan)
+static int lchan2lch_par(GsmL1_LogChParam_t *lch_par, struct gsm_lchan *lchan)
 {
 	struct amr_multirate_conf *amr_mrc = &lchan->tch.amr_mr;
 	struct gsm48_multi_rate_conf *mr_conf =
 			(struct gsm48_multi_rate_conf *) amr_mrc->gsm48_ie;
 	int j;
 
-	LOGP(DL1C, LOGL_INFO, "%s: %s tch_mode=0x%02x\n",
-		gsm_lchan_name(lchan), __FUNCTION__, lchan->tch_mode);
+	LOGPLCHAN(lchan, DL1C, LOGL_INFO, ": %s tch_mode=0x%02x\n", __func__, lchan->tch_mode);
 
 	switch (lchan->tch_mode) {
 	case GSM48_CMODE_SIGN:
@@ -962,7 +971,9 @@ static void lchan2lch_par(GsmL1_LogChParam_t *lch_par, struct gsm_lchan *lchan)
 	case GSM48_CMODE_SPEECH_AMR:
 		lch_par->tch.tchPlType = GsmL1_TchPlType_Amr;
 		set_payload_format(lch_par);
-		lch_par->tch.amrCmiPhase = GsmL1_AmrCmiPhase_Odd; /* FIXME? */
+		/* At call set-up, after every successful handover and after a channel mode modify, the
+		 * default phase (odd) shall be used in downlink direction. */
+		lch_par->tch.amrCmiPhase = GsmL1_AmrCmiPhase_Odd;
 		lch_par->tch.amrInitCodecMode = amr_get_initial_mode(lchan);
 
 		/* initialize to clean state */
@@ -1011,10 +1022,13 @@ static void lchan2lch_par(GsmL1_LogChParam_t *lch_par, struct gsm_lchan *lchan)
 	case GSM48_CMODE_DATA_12k0:
 	case GSM48_CMODE_DATA_6k0:
 	case GSM48_CMODE_DATA_3k6:
-		LOGP(DL1C, LOGL_ERROR, "%s: CSD not supported!\n",
-			gsm_lchan_name(lchan));
-		break;
+	default:
+		LOGPLCHAN(lchan, DL1C, LOGL_ERROR, "Channel mode %s is not supported!\n",
+			  gsm48_chan_mode_name(lchan->tch_mode));
+		return -ENOTSUP;
 	}
+
+	return 0;
 }
 
 static int mph_send_activate_req(struct gsm_lchan *lchan, struct sapi_cmd *cmd)
@@ -1023,6 +1037,7 @@ static int mph_send_activate_req(struct gsm_lchan *lchan, struct sapi_cmd *cmd)
 	struct msgb *msg = l1p_msgb_alloc();
 	int sapi = cmd->sapi;
 	int dir = cmd->dir;
+	int rc;
 	GsmL1_MphActivateReq_t *act_req;
 	GsmL1_LogChParam_t *lch_par;
 
@@ -1045,7 +1060,10 @@ static int mph_send_activate_req(struct gsm_lchan *lchan, struct sapi_cmd *cmd)
 		break;
 	case GsmL1_Sapi_TchH:
 	case GsmL1_Sapi_TchF:
-		lchan2lch_par(lch_par, lchan);
+		if ((rc = lchan2lch_par(lch_par, lchan)) != 0) {
+			talloc_free(msg);
+			return rc;
+		}
 		/*
 		 * Be sure that every packet is received, even if it
 		 * fails. In this case the length might be lower or 0.
@@ -1078,9 +1096,9 @@ static int mph_send_activate_req(struct gsm_lchan *lchan, struct sapi_cmd *cmd)
 		break;
 	}
 
-	LOGP(DL1C, LOGL_INFO, "%s MPH-ACTIVATE.req (hL2=0x%08x, %s ",
-		gsm_lchan_name(lchan), act_req->hLayer2,
-		get_value_string(femtobts_l1sapi_names, act_req->sapi));
+	LOGPLCHAN(lchan, DL1C, LOGL_INFO, "MPH-ACTIVATE.req (hL2=0x%08x, %s ", act_req->hLayer2,
+		  get_value_string(femtobts_l1sapi_names, act_req->sapi));
+	dump_lch_par(LOGL_INFO, lch_par, act_req->sapi);
 	LOGPC(DL1C, LOGL_INFO, "%s)\n",
 		get_value_string(femtobts_dir_names, act_req->dir));
 
@@ -1104,9 +1122,7 @@ static int sapi_activate_cb(struct gsm_lchan *lchan, int status)
 
 	/* FIXME: Error handling */
 	if (status != GsmL1_Status_Success) {
-		LOGP(DL1C, LOGL_ERROR,
-			"%s act failed mark broken due status: %d\n",
-			gsm_lchan_name(lchan), status);
+		LOGPLCHAN(lchan, DL1C, LOGL_ERROR, "act failed mark broken due status: %d\n", status);
 		lchan_set_state(lchan, LCHAN_S_BROKEN);
 		sapi_clear_queue(&lchan->sapi_cmds);
 		mph_info_chan_confirm(lchan, PRIM_INFO_ACTIVATE, RSL_ERR_PROCESSOR_OVERLOAD);
@@ -1153,14 +1169,12 @@ int lchan_activate(struct gsm_lchan *lchan)
 	lchan_set_state(lchan, LCHAN_S_ACT_REQ);
 
 	if (!llist_empty(&lchan->sapi_cmds))
-		LOGP(DL1C, LOGL_ERROR,
-			"%s Trying to activate lchan, but commands in queue\n",
-			gsm_lchan_name(lchan));
+		LOGPLCHAN(lchan, DL1C, LOGL_ERROR, "Trying to activate lchan, but commands in queue\n");
 
-	/* override the regular SAPIs if this is the first hand-over
-	 * related activation of the LCHAN */
+	/* For handover, always start the main channel immediately. lchan->want_dl_sacch_active indicates whether dl
+	 * SACCH should be activated. */
 	if (lchan->ho.active == HANDOVER_ENABLED)
-		s4l = &sapis_for_ho;
+		enqueue_sapi_act_cmd(lchan, GsmL1_Sapi_Rach, GsmL1_Dir_RxUplink);
 
 	for (i = 0; i < s4l->num_sapis; i++) {
 		int sapi = s4l->sapis[i].sapi;
@@ -1173,12 +1187,13 @@ int lchan_activate(struct gsm_lchan *lchan)
 			fl1h->alive_prim_cnt = 0;
 			osmo_timer_schedule(&fl1h->alive_timer, 5, 0);
 		}
+
+		/* For handover, possibly postpone activating the dl SACCH until the HO RACH is received. */
+		if (sapi == GsmL1_Sapi_Sacch && dir == GsmL1_Dir_TxDownlink
+		    && !lchan->want_dl_sacch_active)
+			continue;
 		enqueue_sapi_act_cmd(lchan, sapi, dir);
 	}
-
-#warning "FIXME: Should this be in sapi_activate_cb?"
-	lchan_init_lapdm(lchan);
-
 	return 0;
 }
 
@@ -1264,9 +1279,8 @@ static int chmod_modif_compl_cb(struct gsm_bts_trx *trx, struct msgb *l1_msg,
 		goto err;
 	}
 
-	LOGP(DL1C, LOGL_INFO, "%s MPH-CONFIG.conf (%s) ",
-		gsm_lchan_name(lchan),
-		get_value_string(femtobts_l1cfgt_names, cc->cfgParamId));
+	LOGPLCHAN(lchan, DL1C, LOGL_INFO, "MPH-CONFIG.conf (%s) ",
+		  get_value_string(femtobts_l1cfgt_names, cc->cfgParamId));
 
 	switch (cc->cfgParamId) {
 	case GsmL1_ConfigParamId_SetLogChParams:
@@ -1298,9 +1312,7 @@ static int chmod_modif_compl_cb(struct gsm_bts_trx *trx, struct msgb *l1_msg,
 			break;
 		}
 		if (llist_empty(&lchan->sapi_cmds)) {
-			LOGP(DL1C, LOGL_ERROR,
-				"%s Got ciphering conf with empty queue\n",
-				gsm_lchan_name(lchan));
+			LOGPLCHAN(lchan, DL1C, LOGL_ERROR, "Got ciphering conf with empty queue\n");
 			goto err;
 		}
 
@@ -1325,6 +1337,7 @@ static int mph_send_config_logchpar(struct gsm_lchan *lchan, struct sapi_cmd *cm
 	struct msgb *msg = l1p_msgb_alloc();
 	GsmL1_MphConfigReq_t *conf_req;
 	GsmL1_LogChParam_t *lch_par;
+	int rc;
 
 	/* channel mode, encryption and/or multirate have changed */
 
@@ -1339,7 +1352,10 @@ static int mph_send_config_logchpar(struct gsm_lchan *lchan, struct sapi_cmd *cm
 	conf_req->hLayer3 = l1if_lchan_to_hLayer(lchan);
 
 	lch_par = &conf_req->cfgParams.setLogChParams.logChParams;
-	lchan2lch_par(lch_par, lchan);
+	if ((rc = lchan2lch_par(lch_par, lchan)) != 0) {
+		talloc_free(msg);
+		return rc;
+	}
 
 	/* Update the MS Power Level */
 	if (cmd->sapi == GsmL1_Sapi_Sacch && trx_ms_pwr_ctrl_is_osmo(trx))
@@ -1347,10 +1363,8 @@ static int mph_send_config_logchpar(struct gsm_lchan *lchan, struct sapi_cmd *cm
 
 	/* FIXME: update encryption */
 
-	LOGP(DL1C, LOGL_INFO, "%s MPH-CONFIG.req (%s) ",
-		gsm_lchan_name(lchan),
-		get_value_string(femtobts_l1sapi_names,
-				 conf_req->cfgParams.setLogChParams.sapi));
+	LOGPLCHAN(lchan, DL1C, LOGL_INFO, "MPH-CONFIG.req (%s) ",
+		  get_value_string(femtobts_l1sapi_names, conf_req->cfgParams.setLogChParams.sapi));
 	LOGPC(DL1C, LOGL_INFO, "cfgParams Tn=%u, subCh=%u, dir=0x%x ",
 			conf_req->cfgParams.setLogChParams.u8Tn,
 			conf_req->cfgParams.setLogChParams.subCh,
@@ -1417,11 +1431,9 @@ static int mph_send_config_ciphering(struct gsm_lchan *lchan, struct sapi_cmd *c
 		return -EINVAL;
 	cfgr->cfgParams.setCipheringParams.cipherId = rsl2l1_ciph[lchan->encr.alg_id];
 
-	LOGP(DL1C, LOGL_NOTICE, "%s SET_CIPHERING (ALG=%u %s)\n",
-		gsm_lchan_name(lchan),
-		cfgr->cfgParams.setCipheringParams.cipherId,
-		get_value_string(femtobts_dir_names,
-				 cfgr->cfgParams.setCipheringParams.dir));
+	LOGPLCHAN(lchan, DL1C, LOGL_NOTICE, "SET_CIPHERING (ALG=%u %s)\n",
+		  cfgr->cfgParams.setCipheringParams.cipherId,
+		  get_value_string(femtobts_dir_names, cfgr->cfgParams.setCipheringParams.dir));
 
 	memcpy(cfgr->cfgParams.setCipheringParams.u8Kc,
 	       lchan->encr.key, lchan->encr.key_len);
@@ -1458,6 +1470,16 @@ int l1if_set_ciphering(struct femtol1_hdl *fl1h,
 	return 0;
 }
 
+int l1if_set_ul_acc(struct gsm_lchan *lchan, bool active)
+{
+	if (active)
+		enqueue_sapi_act_cmd(lchan, GsmL1_Sapi_Rach, GsmL1_Dir_RxUplink);
+	else
+		check_sapi_release(lchan, GsmL1_Sapi_Rach, GsmL1_Dir_RxUplink);
+
+	return 0;
+}
+
 int bts_model_adjst_ms_pwr(struct gsm_lchan *lchan)
 {
 	if (lchan->state != LCHAN_S_ACTIVE)
@@ -1499,9 +1521,8 @@ static int lchan_deact_compl_cb(struct gsm_bts_trx *trx, struct msgb *l1_msg,
 		goto err;
 	}
 
-	LOGP(DL1C, LOGL_INFO, "%s MPH-DEACTIVATE.conf (%s ",
-		gsm_lchan_name(lchan),
-		get_value_string(femtobts_l1sapi_names, ic->sapi));
+	LOGPLCHAN(lchan, DL1C, LOGL_INFO, "MPH-DEACTIVATE.conf (%s ",
+		  get_value_string(femtobts_l1sapi_names, ic->sapi));
 	LOGPC(DL1C, LOGL_INFO, "%s)\n",
 		get_value_string(femtobts_dir_names, ic->dir));
 
@@ -1523,19 +1544,15 @@ static int lchan_deact_compl_cb(struct gsm_bts_trx *trx, struct msgb *l1_msg,
 
 
 	if (llist_empty(&lchan->sapi_cmds)) {
-		LOGP(DL1C, LOGL_ERROR,
-				"%s Got de-activation confirmation with empty queue\n",
-				gsm_lchan_name(lchan));
+		LOGPLCHAN(lchan, DL1C, LOGL_ERROR, "Got de-activation confirmation with empty queue\n");
 		goto err;
 	}
 
 	cmd = llist_entry(lchan->sapi_cmds.next, struct sapi_cmd, entry);
 	if (cmd->sapi != ic->sapi || cmd->dir != ic->dir ||
 			cmd->type != SAPI_CMD_DEACTIVATE) {
-		LOGP(DL1C, LOGL_ERROR,
-				"%s Confirmation mismatch (%d, %d) (%d, %d)\n",
-				gsm_lchan_name(lchan), cmd->sapi, cmd->dir,
-				ic->sapi, ic->dir);
+		LOGPLCHAN(lchan, DL1C, LOGL_ERROR, "Confirmation mismatch (%d, %d) (%d, %d)\n",
+			 cmd->sapi, cmd->dir, ic->sapi, ic->dir);
 		goto err;
 	}
 
@@ -1560,8 +1577,7 @@ static int mph_send_deactivate_req(struct gsm_lchan *lchan, struct sapi_cmd *cmd
 	deact_req->sapi = cmd->sapi;
 	deact_req->hLayer3 = l1if_lchan_to_hLayer(lchan);
 
-	LOGP(DL1C, LOGL_INFO, "%s MPH-DEACTIVATE.req (%s ",
-		gsm_lchan_name(lchan),
+	LOGPLCHAN(lchan, DL1C, LOGL_INFO, "MPH-DEACTIVATE.req (%s ",
 		get_value_string(femtobts_l1sapi_names, deact_req->sapi));
 	LOGPC(DL1C, LOGL_INFO, "%s)\n",
 		get_value_string(femtobts_dir_names, deact_req->dir));
@@ -1574,8 +1590,7 @@ static int sapi_deactivate_cb(struct gsm_lchan *lchan, int status)
 {
 	/* FIXME: Error handling. There is no NACK... */
 	if (status != GsmL1_Status_Success && lchan->state == LCHAN_S_REL_REQ) {
-		LOGP(DL1C, LOGL_ERROR, "%s is now broken. Stopping the release.\n",
-			gsm_lchan_name(lchan));
+		LOGPLCHAN(lchan, DL1C, LOGL_ERROR, "is now broken. Stopping the release.\n");
 		lchan_set_state(lchan, LCHAN_S_BROKEN);
 		sapi_clear_queue(&lchan->sapi_cmds);
 		mph_info_chan_confirm(lchan, PRIM_INFO_DEACTIVATE, 0);
@@ -1632,17 +1647,9 @@ static int check_sapi_release(struct gsm_lchan *lchan, int sapi, int dir)
 	return enqueue_sapi_deact_cmd(lchan, sapi, dir);
 }
 
-static int release_sapis_for_ho(struct gsm_lchan *lchan)
+static int release_sapi_ul_rach(struct gsm_lchan *lchan)
 {
-	int res = 0;
-	int i;
-
-	const struct lchan_sapis *s4l = &sapis_for_ho;
-
-	for (i = s4l->num_sapis-1; i >= 0; i--)
-		res |= check_sapi_release(lchan,
-				s4l->sapis[i].sapi, s4l->sapis[i].dir);
-	return res;
+	return check_sapi_release(lchan, GsmL1_Sapi_Rach, GsmL1_Dir_RxUplink);
 }
 
 static int lchan_deactivate_sapis(struct gsm_lchan *lchan)
@@ -1664,12 +1671,11 @@ static int lchan_deactivate_sapis(struct gsm_lchan *lchan)
 	}
 
 	/* always attempt to disable the RACH burst */
-	res |= release_sapis_for_ho(lchan);
+	res |= release_sapi_ul_rach(lchan);
 
 	/* nothing was queued */
 	if (res == 0) {
-		LOGP(DL1C, LOGL_ERROR, "%s all SAPIs already released?\n",
-			gsm_lchan_name(lchan));
+		LOGPLCHAN(lchan, DL1C, LOGL_ERROR, "all SAPIs already released?\n");
 		lchan_set_state(lchan, LCHAN_S_BROKEN);
 		mph_info_chan_confirm(lchan, PRIM_INFO_DEACTIVATE, 0);
 	}
@@ -1716,67 +1722,55 @@ int bts_model_check_oml(struct gsm_bts *bts, uint8_t msg_type,
 			void *obj)
 {
 	/* FIXME: more checks if the attributes are valid */
-
-	switch (msg_type) {
-	case NM_MT_SET_CHAN_ATTR:
-		/* our L1 only supports one global TSC for all channels
-		 * one one TRX, so we need to make sure not to activate
-		 * channels with a different TSC!! */
-		if (TLVP_PRES_LEN(new_attr, NM_ATT_TSC, 1) &&
-		    *TLVP_VAL(new_attr, NM_ATT_TSC) != (bts->bsic & 7)) {
-			LOGP(DOML, LOGL_ERROR, "Channel TSC %u != BSIC-TSC %u\n",
-				*TLVP_VAL(new_attr, NM_ATT_TSC), bts->bsic & 7);
-			return -NM_NACK_PARAM_RANGE;
-		}
-		break;
-	}
 	return 0;
 }
 
 /* callback from OML */
-int bts_model_apply_oml(struct gsm_bts *bts, struct msgb *msg,
-			struct tlv_parsed *new_attr, int kind, void *obj)
+int bts_model_apply_oml(struct gsm_bts *bts, const struct msgb *msg,
+			struct gsm_abis_mo *mo, void *obj)
 {
-	if (kind == NM_OC_RADIO_CARRIER) {
-		struct gsm_bts_trx *trx = obj;
-		struct femtol1_hdl *fl1h = trx_femtol1_hdl(trx);
+	struct abis_om_fom_hdr *foh = msgb_l3(msg);
+	struct gsm_bts_trx *trx;
+	struct femtol1_hdl *fl1h;
+
+	switch (foh->msg_type) {
+	case NM_MT_SET_RADIO_ATTR:
+		trx = obj;
+		fl1h = trx_femtol1_hdl(trx);
 
 		/* Did we go through MphInit yet? If yes fire and forget */
 		if (fl1h->hLayer1)
-			power_ramp_start(trx, get_p_target_mdBm(trx, 0), 0);
+			power_ramp_start(trx, get_p_target_mdBm(trx, 0), 0, NULL);
+		break;
 	}
 
-	/* FIXME: we actaully need to send a ACK or NACK for the OML message */
-	return oml_fom_ack_nack(msg, 0);
+	return 0;
 }
 
 /* callback from OML */
 int bts_model_opstart(struct gsm_bts *bts, struct gsm_abis_mo *mo,
 		      void *obj)
 {
+	struct gsm_bts_trx* trx;
+	struct gsm_bts_trx_ts *ts;
 	int rc;
 
 	switch (mo->obj_class) {
-	case NM_OC_RADIO_CARRIER:
-		rc = trx_init(obj);
-		break;
-	case NM_OC_CHANNEL:
-		rc = ts_opstart(obj);
-		break;
-	case NM_OC_BTS:
 	case NM_OC_SITE_MANAGER:
+	case NM_OC_BTS:
 	case NM_OC_BASEB_TRANSC:
 	case NM_OC_GPRS_NSE:
 	case NM_OC_GPRS_CELL:
 	case NM_OC_GPRS_NSVC:
-		oml_mo_state_chg(mo, NM_OPSTATE_ENABLED, -1);
-		rc = oml_mo_opstart_ack(mo);
-		if (mo->obj_class == NM_OC_BTS) {
-			oml_mo_state_chg(&bts->mo, -1, NM_AVSTATE_OK);
-			oml_mo_state_chg(&bts->gprs.nse.mo, -1, NM_AVSTATE_OK);
-			oml_mo_state_chg(&bts->gprs.cell.mo, -1, NM_AVSTATE_OK);
-			oml_mo_state_chg(&bts->gprs.nsvc[0].mo, -1, NM_AVSTATE_OK);
-		}
+		rc = osmo_fsm_inst_dispatch(mo->fi, NM_EV_OPSTART_ACK, NULL);
+		break;
+	case NM_OC_RADIO_CARRIER:
+		trx = (struct gsm_bts_trx *) obj;
+		rc = trx_init(trx);
+		break;
+	case NM_OC_CHANNEL:
+		ts = (struct gsm_bts_trx_ts*) obj;
+		rc = ts_opstart(ts);
 		break;
 	default:
 		rc = oml_mo_opstart_nack(mo, NM_NACK_OBJCLASS_NOTSUPP);
@@ -1847,24 +1841,26 @@ int l1if_rsl_chan_act(struct gsm_lchan *lchan)
  */
 int l1if_rsl_chan_mod(struct gsm_lchan *lchan)
 {
-	const struct lchan_sapis *s4l = &sapis_for_lchan[lchan->type];
-	unsigned int i;
-
 	if (lchan->ho.active == HANDOVER_NONE)
 		return -1;
 
-	LOGP(DHO, LOGL_ERROR, "%s modifying channel for handover\n",
-		gsm_lchan_name(lchan));
+	LOGPLCHAN(lchan, DHO, LOGL_ERROR, "modifying channel for handover\n");
 
 	/* Give up listening to RACH bursts */
-	release_sapis_for_ho(lchan);
-
-	/* Activate the normal SAPIs */
-	for (i = 0; i < s4l->num_sapis; i++) {
-		int sapi = s4l->sapis[i].sapi;
-		int dir = s4l->sapis[i].dir;
-		enqueue_sapi_act_cmd(lchan, sapi, dir);
-	}
+	release_sapi_ul_rach(lchan);
+
+	/* All the normal SAPIs have already been activated, only DL SACCH may still be missing.
+	 *
+	 * Note: theoretically, it would only be necessary to activate the DL SACCH when it is not active yet.  With
+	 * repeated HO RACH received, we shouldn't need to re-send the SAPI activation every time. However, tests with
+	 * sysmoBTS show that when sending this SAPI activation only once, the lchan will release some seconds after a
+	 * handover, with error messages indicating "Lost SACCH block, faking meas reports and ms pwr".  When re-sending
+	 * the SAPI activation for every RACH received, the problem goes away.
+	 * Before introducing lchan->want_dl_sacch_active, this code here would activate all SAPIs for the main channel,
+	 * which would also repeat for each RACH received. Now we only activate DL SACCH here.
+	 */
+	if (lchan->want_dl_sacch_active)
+		enqueue_sapi_act_cmd(lchan, GsmL1_Sapi_Sacch, GsmL1_Dir_TxDownlink);
 
 	return 0;
 }
@@ -1873,8 +1869,7 @@ int l1if_rsl_chan_rel(struct gsm_lchan *lchan)
 {
 	/* A duplicate RF Release Request, ignore it */
 	if (lchan->state == LCHAN_S_REL_REQ) {
-		LOGP(DL1C, LOGL_ERROR, "%s already in release request state.\n",
-			gsm_lchan_name(lchan));
+		LOGPLCHAN(lchan, DL1C, LOGL_ERROR, "already in release request state.\n");
 		return 0;
 	}
 
@@ -1910,8 +1905,7 @@ static int ts_disconnect_cb(struct gsm_bts_trx *trx, struct msgb *l1_msg,
 	struct gsm_bts_trx_ts *ts = &trx->ts[cnf->u8Tn];
 	OSMO_ASSERT(cnf->u8Tn < TRX_NR_TS);
 
-	LOGP(DL1C, LOGL_DEBUG, "%s Rx mphDisconnectCnf\n",
-	     gsm_lchan_name(ts->lchan));
+	LOGPLCHAN(ts->lchan, DL1C, LOGL_DEBUG, "Rx mphDisconnectCnf\n");
 
 	cb_ts_disconnected(ts);
 
@@ -1924,7 +1918,7 @@ int bts_model_ts_disconnect(struct gsm_bts_trx_ts *ts)
 	struct femtol1_hdl *fl1h = trx_femtol1_hdl(ts->trx);
 	GsmL1_MphDisconnectReq_t *cr;
 
-	DEBUGP(DRSL, "%s TS disconnect\n", gsm_lchan_name(ts->lchan));
+	LOGPLCHAN(ts->lchan, DRSL, LOGL_DEBUG, "TS disconnect\n");
 	cr = prim_init(msgb_l1prim(msg), GsmL1_PrimId_MphDisconnectReq, fl1h,
 		       l1p_handle_for_ts(ts));
 	cr->u8Tn = ts->nr;
@@ -1940,8 +1934,7 @@ static int ts_connect_cb(struct gsm_bts_trx *trx, struct msgb *l1_msg,
 	struct gsm_bts_trx_ts *ts = &trx->ts[cnf->u8Tn];
 	OSMO_ASSERT(cnf->u8Tn < TRX_NR_TS);
 
-	DEBUGP(DL1C, "%s %s Rx mphConnectCnf flags=%s%s%s\n",
-	       gsm_lchan_name(ts->lchan),
+	LOGPLCHAN(ts->lchan, DL1C, LOGL_DEBUG, "%s Rx mphConnectCnf flags=%s%s%s\n",
 	       gsm_pchan_name(ts->pchan),
 	       ts->flags & TS_F_PDCH_ACTIVE ? "ACTIVE " : "",
 	       ts->flags & TS_F_PDCH_ACT_PENDING ? "ACT_PENDING " : "",