xref: /openbmc/btbridge/btbridged.c (revision 825022b4)
1 /* Copyright 2015 IBM
2  *
3  * Licensed under the Apache License, Version 2.0 (the "License");
4  * you may not use this file except in compliance with the License.
5  * You may obtain a copy of the License at
6  *
7  *    http://www.apache.org/licenses/LICENSE-2.0
8  *
9  *	Unless required by applicable law or agreed to in writing, software
10  *	distributed under the License is distributed on an "AS IS" BASIS,
11  *	WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
12  *	See the License for the specific language governing permissions and
13  *	limitations under the License.
14  */
15 
16 #include <assert.h>
17 #include <errno.h>
18 #include <fcntl.h>
19 #include <getopt.h>
20 #include <limits.h>
21 #include <poll.h>
22 #include <stdint.h>
23 #include <stdio.h>
24 #include <stdlib.h>
25 #include <string.h>
26 #include <syslog.h>
27 #include <sys/mman.h>
28 #include <sys/ioctl.h>
29 #include <sys/stat.h>
30 #include <sys/timerfd.h>
31 #include <time.h>
32 #include <unistd.h>
33 
34 #include <linux/bt-bmc.h>
35 
36 #include <systemd/sd-bus.h>
37 
38 static const char *bt_bmc_device = "/dev/ipmi-bt-host";
39 
40 #define PREFIX "BTBRIDGED"
41 
42 #define BT_BMC_PATH bt_bmc_device
43 #define BT_BMC_TIMEOUT_SEC 1
44 #define BT_MAX_MESSAGE 64
45 
46 #define DBUS_NAME "org.openbmc.HostIpmi"
47 #define OBJ_NAME "/org/openbmc/HostIpmi/1"
48 
49 #define SD_BUS_FD 0
50 #define BT_FD 1
51 #define TIMER_FD 2
52 #define TOTAL_FDS 3
53 
54 #define MSG_OUT(f_, ...) do { if (verbosity != BT_LOG_NONE) { bt_log(LOG_INFO, f_, ##__VA_ARGS__); } } while(0)
55 #define MSG_ERR(f_, ...) do { if (verbosity != BT_LOG_NONE) { bt_log(LOG_ERR, f_, ##__VA_ARGS__); } } while(0)
56 
57 struct ipmi_msg {
58 	uint8_t netfn;
59 	uint8_t lun;
60 	uint8_t seq;
61 	uint8_t cmd;
62 	uint8_t cc; /* Only used on responses */
63 	uint8_t *data;
64 	size_t data_len;
65 };
66 
67 struct bt_queue {
68 	struct ipmi_msg req;
69 	struct ipmi_msg rsp;
70 	struct timespec start;
71 	int expired;
72 	sd_bus_message *call;
73 	struct bt_queue *next;
74 };
75 
76 struct btbridged_context {
77 	struct pollfd fds[TOTAL_FDS];
78 	struct sd_bus *bus;
79 	struct bt_queue *bt_q;
80 };
81 
82 static void (*bt_vlog)(int p, const char *fmt, va_list args);
83 static int running = 1;
84 static enum {
85    BT_LOG_NONE = 0,
86    BT_LOG_VERBOSE,
87    BT_LOG_DEBUG
88 } verbosity;
89 
90 static void bt_log_console(int p, const char *fmt, va_list args)
91 {
92 	struct timespec time;
93 	FILE *s = (p < LOG_WARNING) ? stdout : stderr;
94 
95 	clock_gettime(CLOCK_REALTIME, &time);
96 
97 	fprintf(s, "[%s %ld.%.9ld] ", PREFIX, time.tv_sec, time.tv_nsec);
98 
99 	vfprintf(s, fmt, args);
100 }
101 
102 __attribute__((format(printf, 2, 3)))
103 static void bt_log(int p, const char *fmt, ...)
104 {
105 	va_list args;
106 
107 	va_start(args, fmt);
108 	bt_vlog(p, fmt, args);
109 	va_end(args);
110 }
111 
112 static struct bt_queue *bt_q_get_head(struct btbridged_context *context)
113 {
114 	return context ? context->bt_q : NULL;
115 }
116 
117 static struct bt_queue *bt_q_get_seq(struct btbridged_context *context, uint8_t seq)
118 {
119 	struct bt_queue *t;
120 
121 	assert(context);
122 
123 	t = context->bt_q;
124 
125 	while (t && t->req.seq != seq)
126 		t = t->next;
127 
128 	return t;
129 }
130 
131 static struct bt_queue *bt_q_get_msg(struct btbridged_context *context)
132 {
133 	struct bt_queue *t;
134 
135 	assert(context);
136 
137 	t = context->bt_q;
138 
139 	while (t && (!t->call && !t->expired))
140 		t = t->next;
141 
142 	return t;
143 }
144 
145 static struct bt_queue *bt_q_enqueue(struct btbridged_context *context, uint8_t *bt_data)
146 {
147 	struct bt_queue *n;
148 	struct bt_queue *bt_q;
149 	int len;
150 
151 	assert(context && bt_data);
152 
153 	/*
154 	 * len here is the length of the array.
155 	 * Helpfully BT doesn't count the length byte
156 	 */
157 	len = bt_data[0] + 1;
158 	if (len < 4) {
159 		MSG_ERR("Trying to queue a BT message with a short length (%d)\n", len);
160 		return NULL;
161 	}
162 
163 	bt_q = context->bt_q;
164 
165 	n = calloc(1, sizeof(struct bt_queue));
166 	if (!n)
167 		return NULL;
168 
169 	if (verbosity == BT_LOG_DEBUG) {
170 		n->req.data = malloc(len - 4);
171 		if (n->req.data)
172 			n->req.data = memcpy(n->req.data, bt_data + 4, len - 4);
173 	}
174 	n->req.data_len = len - 4;
175 	/* Don't count the lenfn/ln, seq and command */
176 	n->req.netfn = bt_data[1] >> 2;
177 	n->req.lun = bt_data[1] & 0x3;
178 	n->req.seq = bt_data[2];
179 	n->req.cmd = bt_data[3];
180 	if (clock_gettime(CLOCK_MONOTONIC, &n->start) == -1) {
181 		MSG_ERR("Couldn't clock_gettime(): %s\n", strerror(errno));
182 		free(n);
183 		return NULL;
184 	}
185 	if (!bt_q) {
186 		context->bt_q = n;
187 	} else {
188 		struct bt_queue *t = bt_q;
189 
190 		while (t->next)
191 			t = t->next;
192 
193 		t->next = n;
194 	}
195 
196 	return n;
197 }
198 
199 static void bt_q_free(struct bt_queue *bt_q)
200 {
201 	if (!bt_q)
202 		return;
203 
204 	/* Unrefing sd_bus_message should free(rsp.data) */
205 	if (bt_q->call)
206 		sd_bus_message_unref(bt_q->call);
207 
208 	free(bt_q->req.data);
209 	free(bt_q);
210 }
211 
212 static struct bt_queue *bt_q_drop(struct btbridged_context *context, struct bt_queue *element)
213 {
214 	struct bt_queue *r;
215 
216 	assert(context);
217 
218 	if (!element || !context || !context->bt_q)
219 		return NULL;
220 
221 	if (element == context->bt_q) {
222 		context->bt_q = context->bt_q->next;
223 	} else {
224 		r = context->bt_q;
225 		while (r && r->next != element)
226 			r = r->next;
227 
228 		if (!r) {
229 			MSG_ERR("Didn't find element %p in queue\n", element);
230 			bt_q_free(element);
231 			return NULL;
232 		}
233 		r->next = r->next->next;
234 	}
235 	bt_q_free(element);
236 
237 	return context->bt_q;
238 }
239 
240 static struct bt_queue *bt_q_dequeue(struct btbridged_context *context)
241 {
242 	struct bt_queue *r;
243 	struct bt_queue *bt_q;
244 
245 	assert(context);
246 
247 	bt_q = context->bt_q;
248 	if (!bt_q) {
249 		MSG_ERR("Dequeuing empty queue!\n");
250 		return NULL;
251 	}
252 
253 	r = bt_q->next;
254 	bt_q_free(bt_q);
255 	context->bt_q = r;
256 
257 	return r;
258 }
259 
260 static int method_send_sms_atn(sd_bus_message *msg, void *userdata,
261 			       sd_bus_error *ret_error)
262 {
263 	int r;
264 	struct btbridged_context *bt_fd = userdata;
265 
266 	MSG_OUT("Sending SMS_ATN ioctl (%d) to %s\n",
267 			BT_BMC_IOCTL_SMS_ATN, BT_BMC_PATH);
268 
269 	r = ioctl(bt_fd->fds[BT_FD].fd, BT_BMC_IOCTL_SMS_ATN);
270 	if (r == -1) {
271 		r = errno;
272 		MSG_ERR("Couldn't ioctl() to 0x%x, %s: %s\n", bt_fd->fds[BT_FD].fd, BT_BMC_PATH, strerror(r));
273 		return sd_bus_reply_method_errno(msg, errno, ret_error);
274 	}
275 
276 	r = 0;
277 	return sd_bus_reply_method_return(msg, "x", r);
278 }
279 
280 static int method_send_message(sd_bus_message *msg, void *userdata, sd_bus_error *ret_error)
281 {
282 	struct btbridged_context *context;
283 	struct bt_queue *bt_msg;
284 	uint8_t *data;
285 	size_t data_sz;
286 	uint8_t netfn, lun, seq, cmd, cc;
287 	/*
288 	 * Doesn't say it anywhere explicitly but it looks like returning 0 or
289 	 * negative is BAD...
290 	 */
291 	int r = 1;
292 
293 	context = (struct btbridged_context *)userdata;
294 	if (!context) {
295 		sd_bus_error_set_const(ret_error, "org.openbmc.error", "Internal error");
296 		r = 0;
297 		goto out;
298 	}
299 	r = sd_bus_message_read(msg, "yyyyy", &seq, &netfn, &lun, &cmd, &cc);
300 	if (r < 0) {
301 		MSG_ERR("Couldn't parse leading bytes of message: %s\n", strerror(-r));
302 		sd_bus_error_set_const(ret_error, "org.openbmc.error", "Bad message");
303 		r = -EINVAL;
304 		goto out;
305 	}
306 	r = sd_bus_message_read_array(msg, 'y', (const void **)&data, &data_sz);
307 	if (r < 0) {
308 		MSG_ERR("Couldn't parse data bytes of message: %s\n", strerror(-r));
309 		sd_bus_error_set_const(ret_error, "org.openbmc.error", "Bad message data");
310 		r = -EINVAL;
311 		goto out;
312 	}
313 
314 	bt_msg = bt_q_get_seq(context, seq);
315 	if (!bt_msg) {
316 		sd_bus_error_set_const(ret_error, "org.openbmc.error", "No matching request");
317 		MSG_ERR("Failed to find matching request for dbus method with seq: 0x%02x\n", seq);
318 		r = -EINVAL;
319 		goto out;
320 	}
321 	MSG_OUT("Received a dbus response for msg with seq 0x%02x\n", seq);
322 	bt_msg->call = sd_bus_message_ref(msg);
323 	bt_msg->rsp.netfn = netfn;
324 	bt_msg->rsp.lun = lun;
325 	bt_msg->rsp.seq = seq;
326 	bt_msg->rsp.cmd = cmd;
327 	bt_msg->rsp.cc = cc;
328 	bt_msg->rsp.data_len = data_sz;
329 	/* Because we've ref'ed the msg, I hope we don't need to memcpy data */
330 	bt_msg->rsp.data = data;
331 
332 	/* Now that we have a response */
333 	context->fds[BT_FD].events |= POLLOUT;
334 
335 out:
336 	return r;
337 }
338 
339 static int bt_host_write(struct btbridged_context *context, struct bt_queue *bt_msg)
340 {
341 	struct bt_queue *head;
342 	uint8_t data[BT_MAX_MESSAGE] = { 0 };
343 	sd_bus_message *msg = NULL;
344 	int r = 0, len;
345 
346 	assert(context);
347 
348 	if (!bt_msg)
349 		return -EINVAL;
350 
351 	head = bt_q_get_head(context);
352 	if (bt_msg == head) {
353 		struct itimerspec ts;
354 		/* Need to adjust the timer */
355 		ts.it_interval.tv_sec = 0;
356 		ts.it_interval.tv_nsec = 0;
357 		if (head->next) {
358 			ts.it_value = head->next->start;
359 			ts.it_value.tv_sec += BT_BMC_TIMEOUT_SEC;
360 			MSG_OUT("Adjusting timer for next element\n");
361 		} else {
362 			ts.it_value.tv_nsec = 0;
363 			ts.it_value.tv_sec = 0;
364 			MSG_OUT("Disabling timer, no elements remain in queue\n");
365 		}
366 		r = timerfd_settime(context->fds[TIMER_FD].fd, TFD_TIMER_ABSTIME, &ts, NULL);
367 		if (r == -1)
368 			MSG_ERR("Couldn't set timerfd\n");
369 	}
370 	data[1] = (bt_msg->rsp.netfn << 2) | (bt_msg->rsp.lun & 0x3);
371 	data[2] = bt_msg->rsp.seq;
372 	data[3] = bt_msg->rsp.cmd;
373 	data[4] = bt_msg->rsp.cc;
374 	if (bt_msg->rsp.data_len > sizeof(data) - 5) {
375 		MSG_ERR("Response message size (%zu) too big, truncating\n", bt_msg->rsp.data_len);
376 		bt_msg->rsp.data_len = sizeof(data) - 5;
377 	}
378 	/* netfn/len + seq + cmd + cc = 4 */
379 	data[0] = bt_msg->rsp.data_len + 4;
380 	if (bt_msg->rsp.data_len)
381 		memcpy(data + 5, bt_msg->rsp.data, bt_msg->rsp.data_len);
382 	/* Count the data[0] byte */
383 	len = write(context->fds[BT_FD].fd, data, data[0] + 1);
384 	if (len == -1) {
385 		r = errno;
386 		MSG_ERR("Error writing to %s: %s\n", BT_BMC_PATH, strerror(errno));
387 		if (bt_msg->call) {
388 			r = sd_bus_message_new_method_errno(bt_msg->call, &msg, r, NULL);
389 			if (r < 0)
390 				MSG_ERR("Couldn't create response error\n");
391 		}
392 		goto out;
393 	} else {
394 		if (len != data[0] + 1)
395 			MSG_ERR("Possible short write to %s, desired len: %d, written len: %d\n", BT_BMC_PATH, data[0] + 1, len);
396 		else
397 			MSG_OUT("Successfully wrote %d of %d bytes to %s\n", len, data[0] + 1, BT_BMC_PATH);
398 
399 		if (bt_msg->call) {
400 			r = sd_bus_message_new_method_return(bt_msg->call, &msg);
401 			if (r < 0) {
402 				MSG_ERR("Couldn't create response message\n");
403 				goto out;
404 			}
405 			r = 0; /* Just to be explicit about what we're sending back */
406 			r = sd_bus_message_append(msg, "x", r);
407 			if (r < 0) {
408 				MSG_ERR("Couldn't append result to response\n");
409 				goto out;
410 			}
411 
412 		}
413 	}
414 
415 out:
416 	if (bt_msg->call) {
417 		if (sd_bus_send(context->bus, msg, NULL) < 0)
418 			MSG_ERR("Couldn't send response message\n");
419 		sd_bus_message_unref(msg);
420 	}
421 	bt_q_drop(context, bt_msg);
422 
423 	/*
424 	 * There isn't another message ready to be sent so turn off POLLOUT
425 	 */
426 	if (!bt_q_get_msg(context)) {
427 		MSG_OUT("Turning off POLLOUT for the BT in poll()\n");
428 		context->fds[BT_FD].events = POLLIN;
429 	}
430 
431 	return r;
432 }
433 
434 static int dispatch_timer(struct btbridged_context *context)
435 {
436 	int r = 0;
437 	if (context->fds[TIMER_FD].revents & POLLIN) {
438 		sd_bus_message *msg;
439 		struct bt_queue *head;
440 
441 		head = bt_q_get_head(context);
442 		if (!head) {
443 			/* Odd, timer expired but we didn't have a message to timeout */
444 			MSG_ERR("No message found to send timeout\n");
445 			return 0;
446 		}
447 		if (head->call) {
448 			r = sd_bus_message_new_method_errno(head->call, &msg, ETIMEDOUT, NULL);
449 			if (r < 0) {
450 				MSG_ERR("Couldn't create response error\n");
451 			} else {
452 				if (sd_bus_send(context->bus, msg, NULL) < 0)
453 					MSG_ERR("Couldn't send response message\n");
454 				sd_bus_message_unref(msg);
455 			}
456 			MSG_ERR("Message with seq 0x%02x is being timed out despite "
457 					"appearing to have been responded to. Slow BT?\n", head->rsp.seq);
458 		}
459 
460 		/* Set expiry */
461 		head->expired = 1;
462 		head->rsp.seq = head->req.seq;
463 		head->rsp.netfn = head->req.netfn + 1;
464 		head->rsp.lun = head->req.lun;
465 		head->rsp.cc = 0xce; /* Command response could not be provided */
466 		head->rsp.cmd = head->req.cmd;
467 		/* These should already be zeroed but best to be sure */
468 		head->rsp.data_len = 0;
469 		head->rsp.data = NULL;
470 		head->call = NULL;
471 		MSG_OUT("Timeout on msg with seq: 0x%02x\n", head->rsp.seq);
472 		/* Turn on POLLOUT so we'll write this one next */
473 		context->fds[BT_FD].events |= POLLOUT;
474 	}
475 
476 	return 0;
477 }
478 
479 static int dispatch_sd_bus(struct btbridged_context *context)
480 {
481 	int r = 0;
482 	if (context->fds[SD_BUS_FD].revents) {
483 		r = sd_bus_process(context->bus, NULL);
484 		if (r > 0)
485 			MSG_OUT("Processed %d dbus events\n", r);
486 	}
487 
488 	return r;
489 }
490 
491 static int dispatch_bt(struct btbridged_context *context)
492 {
493 	int err = 0;
494 	int r = 0;
495 
496 	assert(context);
497 
498 	if (context->fds[BT_FD].revents & POLLIN) {
499 		sd_bus_message *msg;
500 		struct bt_queue *new;
501 		uint8_t data[BT_MAX_MESSAGE] = { 0 };
502 
503 		r = read(context->fds[BT_FD].fd, data, sizeof(data));
504 		if (r < 0) {
505 			MSG_ERR("Couldn't read from bt: %s\n", strerror(-r));
506 			goto out1;
507 		}
508 		if (r < data[0] + 1) {
509 			MSG_ERR("Short read from bt (%d vs %d)\n", r, data[0] + 1);
510 			r = 0;
511 			goto out1;
512 		}
513 
514 		new = bt_q_enqueue(context, data);
515 		if (!new) {
516 			r = -ENOMEM;
517 			goto out1;
518 		}
519 		if (new == bt_q_get_head(context)) {
520 			struct itimerspec ts;
521 			/*
522 			 * Enqueued onto an empty list, setup a timer for sending a
523 			 * timeout
524 			 */
525 			ts.it_interval.tv_sec = 0;
526 			ts.it_interval.tv_nsec = 0;
527 			ts.it_value.tv_nsec = 0;
528 			ts.it_value.tv_sec = BT_BMC_TIMEOUT_SEC;
529 			r = timerfd_settime(context->fds[TIMER_FD].fd, 0, &ts, NULL);
530 			if (r == -1)
531 				MSG_ERR("Couldn't set timerfd\n");
532 		}
533 
534 		r = sd_bus_message_new_signal(context->bus, &msg, OBJ_NAME, DBUS_NAME, "ReceivedMessage");
535 		if (r < 0) {
536 			MSG_ERR("Failed to create signal: %s\n", strerror(-r));
537 			goto out1;
538 		}
539 
540 		r = sd_bus_message_append(msg, "yyyy", new->req.seq, new->req.netfn, new->req.lun, new->req.cmd);
541 		if (r < 0) {
542 			MSG_ERR("Couldn't append to signal: %s\n", strerror(-r));
543 			goto out1_free;
544 		}
545 
546 		r = sd_bus_message_append_array(msg, 'y', data + 4, new->req.data_len);
547 		if (r < 0) {
548 			MSG_ERR("Couldn't append array to signal: %s\n", strerror(-r));
549 			goto out1_free;
550 		}
551 
552 		MSG_OUT("Sending dbus signal with seq 0x%02x, netfn 0x%02x, lun 0x%02x, cmd 0x%02x\n",
553 				new->req.seq, new->req.netfn, new->req.lun, new->req.cmd);
554 
555 		if (verbosity == BT_LOG_DEBUG) {
556 			int i;
557 			for (i = 0; i < new->req.data_len; i++) {
558 				if (i % 8 == 0) {
559 					if (i)
560 						printf("\n");
561 					MSG_OUT("\t");
562 				}
563 				printf("0x%02x ", data[i + 4]);
564 			}
565 			if (new->req.data_len)
566 				printf("\n");
567 		}
568 
569 		/* Note we only actually keep the request data in the queue when debugging */
570 		r = sd_bus_send(context->bus, msg, NULL);
571 		if (r < 0) {
572 			MSG_ERR("Couldn't emit dbus signal: %s\n", strerror(-r));
573 			goto out1_free;
574 		}
575 		r = 0;
576 out1_free:
577 		sd_bus_message_unref(msg);
578 out1:
579 		err = r;
580 	}
581 
582 	if (context->fds[BT_FD].revents & POLLOUT) {
583 		struct bt_queue *bt_msg;
584 		bt_msg = bt_q_get_msg(context);
585 		if (!bt_msg) {
586 			/* Odd, this shouldn't really happen */
587 			MSG_ERR("Got a POLLOUT but no message is ready to be written\n");
588 			r = 0;
589 			goto out;
590 		}
591 		r = bt_host_write(context, bt_msg);
592 		if (r < 0)
593 			MSG_ERR("Problem putting request with seq 0x%02x, netfn 0x%02x, lun 0x%02x, cmd 0x%02x, cc 0x%02x\n"
594 					"out to %s", bt_msg->rsp.seq, bt_msg->rsp.netfn, bt_msg->rsp.lun,
595 					bt_msg->rsp.cmd, bt_msg->rsp.cc, BT_BMC_PATH);
596 		else
597 			MSG_OUT("Completed request with seq 0x%02x, netfn 0x%02x, lun 0x%02x, cmd 0x%02x, cc 0x%02x\n",
598 					bt_msg->rsp.seq, bt_msg->rsp.netfn, bt_msg->rsp.lun, bt_msg->rsp.cmd, bt_msg->rsp.cc);
599 	}
600 out:
601 	return err ? err : r;
602 }
603 
604 static void usage(const char *name)
605 {
606 	fprintf(stderr, "\
607 Usage %s [--v[v] | --syslog] [-d <DEVICE>]\n\
608   --v                    Be verbose\n\
609   --vv                   Be verbose and dump entire messages\n\
610   -s, --syslog           Log output to syslog (pointless without --verbose)\n\
611   -d, --device <DEVICE>  use <DEVICE> file. Default is '%s'\n\n",
612 		name, bt_bmc_device);
613 }
614 
615 static const sd_bus_vtable ipmid_vtable[] = {
616 	SD_BUS_VTABLE_START(0),
617 	SD_BUS_METHOD("sendMessage", "yyyyyay", "x", &method_send_message, SD_BUS_VTABLE_UNPRIVILEGED),
618 	SD_BUS_METHOD("setAttention", "", "x", &method_send_sms_atn, SD_BUS_VTABLE_UNPRIVILEGED),
619 	SD_BUS_SIGNAL("ReceivedMessage", "yyyyay", 0),
620 	SD_BUS_VTABLE_END
621 };
622 
623 int main(int argc, char *argv[]) {
624 	struct btbridged_context *context;
625 	const char *name = argv[0];
626 	int opt, polled, r;
627 
628 	static const struct option long_options[] = {
629 		{ "device",  required_argument, NULL, 'd' },
630 		{ "v",       no_argument, (int *)&verbosity, BT_LOG_VERBOSE },
631 		{ "vv",      no_argument, (int *)&verbosity, BT_LOG_DEBUG   },
632 		{ "syslog",  no_argument, 0,          's'         },
633 		{ 0,         0,           0,          0           }
634 	};
635 
636 	context = calloc(1, sizeof(*context));
637 
638 	bt_vlog = &bt_log_console;
639 	while ((opt = getopt_long(argc, argv, "", long_options, NULL)) != -1) {
640 		switch (opt) {
641 			case 0:
642 				break;
643 			case 'd':
644 				bt_bmc_device = optarg;
645 				break;
646 			case 's':
647 				/* Avoid a double openlog() */
648 				if (bt_vlog != &vsyslog) {
649 					openlog(PREFIX, LOG_ODELAY, LOG_DAEMON);
650 					bt_vlog = &vsyslog;
651 				}
652 				break;
653 			default:
654 				usage(name);
655 				exit(EXIT_FAILURE);
656 		}
657 	}
658 
659 	if (verbosity == BT_LOG_VERBOSE)
660 		MSG_OUT("Verbose logging\n");
661 
662 	if (verbosity == BT_LOG_DEBUG)
663 		MSG_OUT("Debug logging\n");
664 
665 	MSG_OUT("Starting\n");
666 	r = sd_bus_default_system(&context->bus);
667 	if (r < 0) {
668 		MSG_ERR("Failed to connect to system bus: %s\n", strerror(-r));
669 		goto finish;
670 	}
671 
672 	MSG_OUT("Registering dbus methods/signals\n");
673 	r = sd_bus_add_object_vtable(context->bus,
674 	                             NULL,
675 	                             OBJ_NAME,
676 	                             DBUS_NAME,
677 	                             ipmid_vtable,
678 	                             context);
679 	if (r < 0) {
680 		MSG_ERR("Failed to issue method call: %s\n", strerror(-r));
681 		goto finish;
682 	}
683 
684 	MSG_OUT("Requesting dbus name: %s\n", DBUS_NAME);
685 	r = sd_bus_request_name(context->bus, DBUS_NAME, SD_BUS_NAME_ALLOW_REPLACEMENT|SD_BUS_NAME_REPLACE_EXISTING);
686 	if (r < 0) {
687 		MSG_ERR("Failed to acquire service name: %s\n", strerror(-r));
688 		goto finish;
689 	}
690 
691 	MSG_OUT("Getting dbus file descriptors\n");
692 	context->fds[SD_BUS_FD].fd = sd_bus_get_fd(context->bus);
693 	if (context->fds[SD_BUS_FD].fd < 0) {
694 		r = -errno;
695 		MSG_OUT("Couldn't get the bus file descriptor: %s\n", strerror(errno));
696 		goto finish;
697 	}
698 
699 	MSG_OUT("Opening %s\n", BT_BMC_PATH);
700 	context->fds[BT_FD].fd = open(BT_BMC_PATH, O_RDWR | O_NONBLOCK);
701 	if (context->fds[BT_FD].fd < 0) {
702 		r = -errno;
703 		MSG_ERR("Couldn't open %s with flags O_RDWR: %s\n", BT_BMC_PATH, strerror(errno));
704 		goto finish;
705 	}
706 
707 	MSG_OUT("Creating timer fd\n");
708 	context->fds[TIMER_FD].fd = timerfd_create(CLOCK_MONOTONIC, 0);
709 	if (context->fds[TIMER_FD].fd < 0) {
710 		r = -errno;
711 		MSG_ERR("Couldn't create timer fd: %s\n", strerror(errno));
712 		goto finish;
713 	}
714 	context->fds[SD_BUS_FD].events = POLLIN;
715 	context->fds[BT_FD].events = POLLIN;
716 	context->fds[TIMER_FD].events = POLLIN;
717 
718 	MSG_OUT("Entering polling loop\n");
719 
720 	while (running) {
721 		polled = poll(context->fds, TOTAL_FDS, 1000);
722 		if (polled == 0)
723 			continue;
724 		if (polled < 0) {
725 			r = -errno;
726 			MSG_ERR("Error from poll(): %s\n", strerror(errno));
727 			goto finish;
728 		}
729 		r = dispatch_sd_bus(context);
730 		if (r < 0) {
731 			MSG_ERR("Error handling dbus event: %s\n", strerror(-r));
732 			goto finish;
733 		}
734 		r = dispatch_bt(context);
735 		if (r < 0) {
736 			MSG_ERR("Error handling BT event: %s\n", strerror(-r));
737 			goto finish;
738 		}
739 		r = dispatch_timer(context);
740 		if (r < 0) {
741 			MSG_ERR("Error handling timer event: %s\n", strerror(-r));
742 			goto finish;
743 		}
744 	}
745 
746 finish:
747 	if (bt_q_get_head(context)) {
748 		MSG_ERR("Unresponded BT Message!\n");
749 		while (bt_q_dequeue(context));
750 	}
751 	close(context->fds[BT_FD].fd);
752 	close(context->fds[TIMER_FD].fd);
753 	sd_bus_unref(context->bus);
754 	free(context);
755 
756 	return r;
757 }
758 
759