posix: convert all error logs to debug logs

In Zephyr, things are often optimized for size first. That's how
we fit into such tight parking spaces.

This change gives more control to the user about whether the
POSIX API does any logging at all, simultaneously shrinking binary
size while improving speed.

No bytes / cycles left behind!

Signed-off-by: Christopher Friedt <[email protected]>

lib/posix/options/cond.c

@@ -45,19 +45,19 @@ static struct k_condvar *get_posix_cond(pthread_cond_t cond)
 
 	/* if the provided cond does not claim to be initialized, its invalid */
 	if (!is_pthread_obj_initialized(cond)) {
-		LOG_ERR("Cond is uninitialized (%x)", cond);
+		LOG_DBG("Cond is uninitialized (%x)", cond);
 		return NULL;
 	}
 
 	/* Mask off the MSB to get the actual bit index */
 	if (sys_bitarray_test_bit(&posix_cond_bitarray, bit, &actually_initialized) < 0) {
-		LOG_ERR("Cond is invalid (%x)", cond);
+		LOG_DBG("Cond is invalid (%x)", cond);
 		return NULL;
 	}
 
 	if (actually_initialized == 0) {
 		/* The cond claims to be initialized but is actually not */
-		LOG_ERR("Cond claims to be initialized (%x)", cond);
+		LOG_DBG("Cond claims to be initialized (%x)", cond);
 		return NULL;
 	}
 
@@ -76,7 +76,7 @@ static struct k_condvar *to_posix_cond(pthread_cond_t *cvar)
 	/* Try and automatically associate a posix_cond */
 	if (sys_bitarray_alloc(&posix_cond_bitarray, 1, &bit) < 0) {
 		/* No conds left to allocate */
-		LOG_ERR("Unable to allocate pthread_cond_t");
+		LOG_DBG("Unable to allocate pthread_cond_t");
 		return NULL;
 	}
 
@@ -102,10 +102,10 @@ static int cond_wait(pthread_cond_t *cond, pthread_mutex_t *mu, k_timeout_t time
 	LOG_DBG("Waiting on cond %p with timeout %llx", cv, timeout.ticks);
 	ret = k_condvar_wait(cv, m, timeout);
 	if (ret == -EAGAIN) {
-		LOG_ERR("Timeout waiting on cond %p", cv);
+		LOG_DBG("Timeout waiting on cond %p", cv);
 		ret = ETIMEDOUT;
 	} else if (ret < 0) {
-		LOG_ERR("k_condvar_wait() failed: %d", ret);
+		LOG_DBG("k_condvar_wait() failed: %d", ret);
 		ret = -ret;
 	} else {
 		__ASSERT_NO_MSG(ret == 0);
@@ -128,7 +128,7 @@ int pthread_cond_signal(pthread_cond_t *cvar)
 	LOG_DBG("Signaling cond %p", cv);
 	ret = k_condvar_signal(cv);
 	if (ret < 0) {
-		LOG_ERR("k_condvar_signal() failed: %d", ret);
+		LOG_DBG("k_condvar_signal() failed: %d", ret);
 		return -ret;
 	}
 
@@ -150,7 +150,7 @@ int pthread_cond_broadcast(pthread_cond_t *cvar)
 	LOG_DBG("Broadcasting on cond %p", cv);
 	ret = k_condvar_broadcast(cv);
 	if (ret < 0) {
-		LOG_ERR("k_condvar_broadcast() failed: %d", ret);
+		LOG_DBG("k_condvar_broadcast() failed: %d", ret);
 		return -ret;
 	}
 

lib/posix/options/getopt/getopt.c

@@ -122,7 +122,7 @@ int getopt(int nargc, char *const nargv[], const char *ostr)
 			++state->optind;
 		}
 		if (state->opterr && *ostr != ':') {
-			LOG_ERR("illegal option -- %c", state->optopt);
+			LOG_DBG("illegal option -- %c", state->optopt);
 		}
 		z_getopt_global_state_update(state);
 		return BADCH;
@@ -151,7 +151,7 @@ int getopt(int nargc, char *const nargv[], const char *ostr)
 				return BADARG;
 			}
 			if (state->opterr) {
-				LOG_ERR("option requires an argument -- %c",
+				LOG_DBG("option requires an argument -- %c",
 					state->optopt);
 			}
 			z_getopt_global_state_update(state);

lib/posix/options/key.c

@@ -52,19 +52,19 @@ static pthread_key_obj *get_posix_key(pthread_key_t key)
 
 	/* if the provided cond does not claim to be initialized, its invalid */
 	if (!is_pthread_obj_initialized(key)) {
-		LOG_ERR("Key is uninitialized (%x)", key);
+		LOG_DBG("Key is uninitialized (%x)", key);
 		return NULL;
 	}
 
 	/* Mask off the MSB to get the actual bit index */
 	if (sys_bitarray_test_bit(&posix_key_bitarray, bit, &actually_initialized) < 0) {
-		LOG_ERR("Key is invalid (%x)", key);
+		LOG_DBG("Key is invalid (%x)", key);
 		return NULL;
 	}
 
 	if (actually_initialized == 0) {
 		/* The cond claims to be initialized but is actually not */
-		LOG_ERR("Key claims to be initialized (%x)", key);
+		LOG_DBG("Key claims to be initialized (%x)", key);
 		return NULL;
 	}
 
@@ -218,7 +218,7 @@ int pthread_setspecific(pthread_key_t key, const void *value)
 		key_data = k_malloc(sizeof(struct pthread_key_data));
 
 		if (key_data == NULL) {
-			LOG_ERR("Failed to allocate key data for key %x", key);
+			LOG_DBG("Failed to allocate key data for key %x", key);
 			retval = ENOMEM;
 			goto out;
 		}

lib/posix/options/mutex.c

@@ -57,19 +57,19 @@ static struct k_mutex *get_posix_mutex(pthread_mutex_t mu)
 
 	/* if the provided mutex does not claim to be initialized, its invalid */
 	if (!is_pthread_obj_initialized(mu)) {
-		LOG_ERR("Mutex is uninitialized (%x)", mu);
+		LOG_DBG("Mutex is uninitialized (%x)", mu);
 		return NULL;
 	}
 
 	/* Mask off the MSB to get the actual bit index */
 	if (sys_bitarray_test_bit(&posix_mutex_bitarray, bit, &actually_initialized) < 0) {
-		LOG_ERR("Mutex is invalid (%x)", mu);
+		LOG_DBG("Mutex is invalid (%x)", mu);
 		return NULL;
 	}
 
 	if (actually_initialized == 0) {
 		/* The mutex claims to be initialized but is actually not */
-		LOG_ERR("Mutex claims to be initialized (%x)", mu);
+		LOG_DBG("Mutex claims to be initialized (%x)", mu);
 		return NULL;
 	}
 
@@ -88,7 +88,7 @@ struct k_mutex *to_posix_mutex(pthread_mutex_t *mu)
 
 	/* Try and automatically associate a posix_mutex */
 	if (sys_bitarray_alloc(&posix_mutex_bitarray, 1, &bit) < 0) {
-		LOG_ERR("Unable to allocate pthread_mutex_t");
+		LOG_DBG("Unable to allocate pthread_mutex_t");
 		return NULL;
 	}
 
@@ -130,25 +130,25 @@ static int acquire_mutex(pthread_mutex_t *mu, k_timeout_t timeout)
 		case PTHREAD_MUTEX_NORMAL:
 			if (K_TIMEOUT_EQ(timeout, K_NO_WAIT)) {
 				k_spin_unlock(&pthread_mutex_spinlock, key);
-				LOG_ERR("Timeout locking mutex %p", m);
+				LOG_DBG("Timeout locking mutex %p", m);
 				return EBUSY;
 			}
 			/* On most POSIX systems, this usually results in an infinite loop */
 			k_spin_unlock(&pthread_mutex_spinlock, key);
-			LOG_ERR("Attempt to relock non-recursive mutex %p", m);
+			LOG_DBG("Attempt to relock non-recursive mutex %p", m);
 			do {
 				(void)k_sleep(K_FOREVER);
 			} while (true);
 			CODE_UNREACHABLE;
 			break;
 		case PTHREAD_MUTEX_RECURSIVE:
 			if (m->lock_count >= MUTEX_MAX_REC_LOCK) {
-				LOG_ERR("Mutex %p locked recursively too many times", m);
+				LOG_DBG("Mutex %p locked recursively too many times", m);
 				ret = EAGAIN;
 			}
 			break;
 		case PTHREAD_MUTEX_ERRORCHECK:
-			LOG_ERR("Attempt to recursively lock non-recursive mutex %p", m);
+			LOG_DBG("Attempt to recursively lock non-recursive mutex %p", m);
 			ret = EDEADLK;
 			break;
 		default:
@@ -162,7 +162,7 @@ static int acquire_mutex(pthread_mutex_t *mu, k_timeout_t timeout)
 	if (ret == 0) {
 		ret = k_mutex_lock(m, timeout);
 		if (ret == -EAGAIN) {
-			LOG_ERR("Timeout locking mutex %p", m);
+			LOG_DBG("Timeout locking mutex %p", m);
 			/*
 			 * special quirk - k_mutex_lock() returns EAGAIN if a timeout occurs, but
 			 * for pthreads, that means something different
@@ -172,7 +172,7 @@ static int acquire_mutex(pthread_mutex_t *mu, k_timeout_t timeout)
 	}
 
 	if (ret < 0) {
-		LOG_ERR("k_mutex_unlock() failed: %d", ret);
+		LOG_DBG("k_mutex_unlock() failed: %d", ret);
 		ret = -ret;
 	}
 
@@ -264,7 +264,7 @@ int pthread_mutex_unlock(pthread_mutex_t *mu)
 
 	ret = k_mutex_unlock(m);
 	if (ret < 0) {
-		LOG_ERR("k_mutex_unlock() failed: %d", ret);
+		LOG_DBG("k_mutex_unlock() failed: %d", ret);
 		return -ret;
 	}
 

lib/posix/options/pthread.c

@@ -144,12 +144,12 @@ struct posix_thread *to_posix_thread(pthread_t pthread)
 
 	/* if the provided thread does not claim to be initialized, its invalid */
 	if (!is_pthread_obj_initialized(pthread)) {
-		LOG_ERR("pthread is not initialized (%x)", pthread);
+		LOG_DBG("pthread is not initialized (%x)", pthread);
 		return NULL;
 	}
 
 	if (bit >= CONFIG_MAX_PTHREAD_COUNT) {
-		LOG_ERR("Invalid pthread (%x)", pthread);
+		LOG_DBG("Invalid pthread (%x)", pthread);
 		return NULL;
 	}
 
@@ -165,7 +165,7 @@ struct posix_thread *to_posix_thread(pthread_t pthread)
 				  t->attr.detachstate == PTHREAD_CREATE_DETACHED));
 
 	if (!actually_initialized) {
-		LOG_ERR("Pthread claims to be initialized (%x)", pthread);
+		LOG_DBG("Pthread claims to be initialized (%x)", pthread);
 		return NULL;
 	}
 
@@ -257,7 +257,7 @@ static bool is_posix_policy_prio_valid(int priority, int policy)
 		return true;
 	}
 
-	LOG_ERR("Invalid priority %d and / or policy %d", priority, policy);
+	LOG_DBG("Invalid priority %d and / or policy %d", priority, policy);
 
 	return false;
 }
@@ -306,7 +306,7 @@ static bool __attr_is_runnable(const struct posix_thread_attr *attr)
 
 	/* require a valid scheduler policy */
 	if (!valid_posix_policy(attr->schedpolicy)) {
-		LOG_ERR("Invalid scheduler policy %d", attr->schedpolicy);
+		LOG_DBG("Invalid scheduler policy %d", attr->schedpolicy);
 		return false;
 	}
 
@@ -338,7 +338,7 @@ int pthread_attr_setschedparam(pthread_attr_t *_attr, const struct sched_param *
 
 	if (!__attr_is_initialized(attr) || schedparam == NULL ||
 	    !is_posix_policy_prio_valid(schedparam->sched_priority, attr->schedpolicy)) {
-		LOG_ERR("Invalid pthread_attr_t or sched_param");
+		LOG_DBG("Invalid pthread_attr_t or sched_param");
 		return EINVAL;
 	}
 
@@ -357,13 +357,13 @@ int pthread_attr_setstack(pthread_attr_t *_attr, void *stackaddr, size_t stacksi
 	struct posix_thread_attr *attr = (struct posix_thread_attr *)_attr;
 
 	if (stackaddr == NULL) {
-		LOG_ERR("NULL stack address");
+		LOG_DBG("NULL stack address");
 		return EACCES;
 	}
 
 	if (!__attr_is_initialized(attr) || stacksize == 0 || stacksize < PTHREAD_STACK_MIN ||
 	    stacksize > PTHREAD_STACK_MAX) {
-		LOG_ERR("Invalid stacksize %zu", stacksize);
+		LOG_DBG("Invalid stacksize %zu", stacksize);
 		return EINVAL;
 	}
 
@@ -531,7 +531,7 @@ int pthread_create(pthread_t *th, const pthread_attr_t *_attr, void *(*threadrou
 
 	if (t == NULL) {
 		/* no threads are ready */
-		LOG_ERR("No threads are ready");
+		LOG_DBG("No threads are ready");
 		return EAGAIN;
 	}
 
@@ -620,7 +620,7 @@ int pthread_setcancelstate(int state, int *oldstate)
 	bool cancel_type = PTHREAD_CANCEL_ENABLE;
 
 	if (state != PTHREAD_CANCEL_ENABLE && state != PTHREAD_CANCEL_DISABLE) {
-		LOG_ERR("Invalid pthread state %d", state);
+		LOG_DBG("Invalid pthread state %d", state);
 		return EINVAL;
 	}
 
@@ -659,7 +659,7 @@ int pthread_setcanceltype(int type, int *oldtype)
 	struct posix_thread *t;
 
 	if (type != PTHREAD_CANCEL_DEFERRED && type != PTHREAD_CANCEL_ASYNCHRONOUS) {
-		LOG_ERR("Invalid pthread cancel type %d", type);
+		LOG_DBG("Invalid pthread cancel type %d", type);
 		return EINVAL;
 	}
 
@@ -789,7 +789,7 @@ int pthread_attr_init(pthread_attr_t *_attr)
 	struct posix_thread_attr *const attr = (struct posix_thread_attr *)_attr;
 
 	if (attr == NULL) {
-		LOG_ERR("Invalid attr pointer");
+		LOG_DBG("Invalid attr pointer");
 		return ENOMEM;
 	}
 
@@ -924,7 +924,7 @@ int pthread_join(pthread_t pthread, void **status)
 	struct posix_thread *t = NULL;
 
 	if (pthread == pthread_self()) {
-		LOG_ERR("Pthread attempted to join itself (%x)", pthread);
+		LOG_DBG("Pthread attempted to join itself (%x)", pthread);
 		return EDEADLK;
 	}
 
@@ -957,10 +957,10 @@ int pthread_join(pthread_t pthread, void **status)
 
 	switch (ret) {
 	case ESRCH:
-		LOG_ERR("Pthread %p has already been joined", &t->thread);
+		LOG_DBG("Pthread %p has already been joined", &t->thread);
 		return ret;
 	case EINVAL:
-		LOG_ERR("Pthread %p is not a joinable", &t->thread);
+		LOG_DBG("Pthread %p is not a joinable", &t->thread);
 		return ret;
 	case 0:
 		break;
@@ -1001,7 +1001,7 @@ int pthread_detach(pthread_t pthread)
 
 		if (posix_thread_q_get(t) == POSIX_THREAD_READY_Q ||
 		    t->attr.detachstate != PTHREAD_CREATE_JOINABLE) {
-			LOG_ERR("Pthread %p cannot be detached", &t->thread);
+			LOG_DBG("Pthread %p cannot be detached", &t->thread);
 			ret = EINVAL;
 			K_SPINLOCK_BREAK;
 		}

lib/posix/options/rwlock.c

@@ -57,19 +57,19 @@ static struct posix_rwlock *get_posix_rwlock(pthread_rwlock_t rwlock)
 
 	/* if the provided rwlock does not claim to be initialized, its invalid */
 	if (!is_pthread_obj_initialized(rwlock)) {
-		LOG_ERR("RWlock is uninitialized (%x)", rwlock);
+		LOG_DBG("RWlock is uninitialized (%x)", rwlock);
 		return NULL;
 	}
 
 	/* Mask off the MSB to get the actual bit index */
 	if (sys_bitarray_test_bit(&posix_rwlock_bitarray, bit, &actually_initialized) < 0) {
-		LOG_ERR("RWlock is invalid (%x)", rwlock);
+		LOG_DBG("RWlock is invalid (%x)", rwlock);
 		return NULL;
 	}
 
 	if (actually_initialized == 0) {
 		/* The rwlock claims to be initialized but is actually not */
-		LOG_ERR("RWlock claims to be initialized (%x)", rwlock);
+		LOG_DBG("RWlock claims to be initialized (%x)", rwlock);
 		return NULL;
 	}
 
@@ -87,7 +87,7 @@ struct posix_rwlock *to_posix_rwlock(pthread_rwlock_t *rwlock)
 
 	/* Try and automatically associate a posix_rwlock */
 	if (sys_bitarray_alloc(&posix_rwlock_bitarray, 1, &bit) < 0) {
-		LOG_ERR("Unable to allocate pthread_rwlock_t");
+		LOG_DBG("Unable to allocate pthread_rwlock_t");
 		return NULL;
 	}