Skip to content

Conversation

sreimers
Copy link
Member

@sreimers sreimers commented May 19, 2022

If dnsc_query is used on a server its possible to add a local dns resolver for caching (like unbound). But on desktop or mobile this is not always possible. Some nameservers/resolvers (e.g. cheap routers) can't handle many dns requests. This PR introduces a query caching (takes into account the lowest resource record TTL).

@sreimers sreimers marked this pull request as ready for review May 19, 2022 21:19
@sreimers sreimers changed the title dns: add query cache (WIP) dns: add query cache May 19, 2022
@sreimers sreimers marked this pull request as draft May 19, 2022 22:13
@sreimers sreimers marked this pull request as ready for review May 20, 2022 19:16
@sreimers
Copy link
Member Author

Something for discussion: Should cached resource records rotate (round robin dns)? Or is it enough to wait until they expire?

@alfredh
Copy link
Contributor

alfredh commented May 21, 2022

does it also handle negative replies, i.e. if a record does not exist does it delete the cache entry ?

some DNS servers return a random order of multiple entries, and some return a fixed order.
it is probably good enough to wait for the entries to expire, it will rebuild the cache next time.

@sreimers
Copy link
Member Author

Negative replies are cached by SOA TTL like described here: https://datatracker.ietf.org/doc/html/rfc2308

	/**
	 * Don't cache empty RR answer if authority is also empty.
	 * Otherwise negative answer is cached with respecting the SOA TTL.
	 */
	if ((!dq.hdr.nans && !dq.hdr.nauth)) {
		mem_deref(q);
		goto out;
	}

@sreimers
Copy link
Member Author

I read a bit more about SOA TTL handling and added a better RFC 2308 check:

	/* Cache negative answer with SOA negative TTL value. (RFC 2308) */
	if (!dq.hdr.nans && dq.hdr.nauth) {
		struct dnsrr *rr = list_ledata(list_head(&q->rrlv[1]));

		if (!rr || rr->type != DNS_TYPE_SOA) {
			mem_deref(q);
			goto out;
		}

		if (rr->rdata.soa.ttlmin < CACHE_TTL_MAX)
			ttl = rr->rdata.soa.ttlmin;
	}

@sreimers sreimers merged commit abcd3ca into main May 23, 2022
@sreimers sreimers deleted the dns_cache branch May 23, 2022 12:32
@juha-h
Copy link
Contributor

juha-h commented May 27, 2022

Is there any intention to make baresip use the caching, i.e., have possibility configure dnsc_cache_max time?

@sreimers
Copy link
Member Author

The caching is enabled by default. I can add a config option in baresip.

@juha-h
Copy link
Contributor

juha-h commented May 27, 2022 via email

@juha-h
Copy link
Contributor

juha-h commented Jun 5, 2022

I suspect that in my Android baresip app DNS caching is sometimes causing about 30 sec delay before INVITE request is sent out. I don't have any proof, but I have not seen the delay after I turned caching off:

err = baresip_init(conf_config());
...
dnsc_cache_max(net_dnsc(baresip_network()), 0);

The account is not using any medianat protocol that could cause the delay.

@sreimers
Copy link
Member Author

sreimers commented Jun 5, 2022

Can you enable the DNS client debug mode?:

--- a/src/dns/client.c
+++ b/src/dns/client.c
@@ -20,7 +20,7 @@
 
 
 #define DEBUG_MODULE "dnsc"
-#define DEBUG_LEVEL 5
+#define DEBUG_LEVEL 6
 #include <re_dbg.h>

You should see all DNS queries and answers, for cached answers "ANSWER SECTION (CACHED)" is printed.

@juha-h
Copy link
Contributor

juha-h commented Jun 5, 2022

It seems to work OK on Linux.

@juha-h
Copy link
Contributor

juha-h commented Jun 5, 2022

But never mind, I can turn the cache off.

@juha-h
Copy link
Contributor

juha-h commented Jun 6, 2022

My Android app does not make any re tmr related calls. But could threads have something to do with this issue?

Android app user interface runs on UI thread. When user makes a call, the app calls native (C) function

JNIEXPORT jlong JNICALL
Java_com_tutpro_baresip_Api_ua_1call_1alloc(JNIEnv *env, jobject thiz, jlong ua, jlong xCall, jint vidMode)
{
    struct call *call = NULL;
    int err;
    re_thread_enter();
    err = ua_call_alloc(&call, (struct ua *)ua, (enum vidmode)vidMode, NULL, (struct call *)xCall,
            call_localuri((struct call *)xCall), true);
    re_thread_leave();
    if (err)
        LOGW("call allocation for ua %ld failed with error %d\n", (long)ua, err);
    return (jlong)call;
}

As shown, it calls re_thread_enter() before calling API function ua_call_alloc() so that the API function is executed on re thread instead of UI thread.

@sreimers
Copy link
Member Author

sreimers commented Jun 6, 2022

But never mind, I can turn the cache off.

Sure, but I'm a little worried about the fact, that such a simple timer callback is broken (works not reliable) on android.
Can you try these patches:

--- a/src/main/main.c
+++ b/src/main/main.c
@@ -695,7 +695,7 @@ static int fd_poll(struct re *re)
        fd_set rfds, wfds, efds;
 #endif
 
-       DEBUG_INFO("next timer: %llu ms\n", to);
+       DEBUG_NOTICE("next timer: %llu ms\n", to);
 
        /* Wait for I/O */
        switch (re->method) {
--- a/src/dns/client.c
+++ b/src/dns/client.c
@@ -20,7 +20,7 @@
 
 #define DEBUG_MODULE "dnsc"
-#define DEBUG_LEVEL 5
+#define DEBUG_LEVEL 6
 #include <re_dbg.h>
 
@@ -761,6 +761,8 @@ static bool query_cache_handler(struct dns_query *q)
        tmr_start(&q->dnsc->hdl_tmr, 0, hdl_tmr_cache, &q->dnsc->hdl_cache);
 
+       DEBUG_NOTICE("%H\n", tmr_debug);
+
        return true;
 }
 

@sreimers
Copy link
Member Author

sreimers commented Jun 6, 2022

As shown, it calls re_thread_enter() before calling API function ua_call_alloc() so that the API function is executed on re thread instead of UI thread.

Should normally be fine, since tmr_poll should be executed after you call re_thread_leave, but maybe there is a race condition I don't see yet.

@juha-h
Copy link
Contributor

juha-h commented Jun 6, 2022

Here is test call logging with the above debugs.

06-06 09:31:40.564  5471  5471 D Baresip Lib: ua event (CALL_OUTGOING) sip:thetestcall@opensips.org
06-06 09:31:40.620  5471  5647 D Baresip Lib: dnsc: --- QUESTION SECTION id: 33977 ---
06-06 09:31:40.620  5471  5647 D Baresip Lib: dnsc: box.tutpro.com.	IN	A
06-06 09:31:40.620  5471  5647 D Baresip Lib: dnsc: Timers (21):
06-06 09:31:40.620  5471  5647 D Baresip Lib:   0x78fe55f028: th=0x7
06-06 09:31:40.620  5471  5647 D Baresip Lib: 89e1c7098 expire=0ms file=src/dns/client.c:762
06-06 09:31:40.620  5471  5647 D Baresip Lib:   0x78a0c93c38: th=0x
06-06 09:31:40.620  5471  5647 D Baresip Lib: 789e188f34 expire=42ms file=src/metric.c
06-06 09:31:40.620  5471  5647 D Baresip Lib: :65
06-06 09:31:40.620  5471  5647 D Baresip Lib:   
06-06 09:31:40.620  5471  5647 D Baresip Lib: 0x78a0c93d20: th=0x789e188f34
06-06 09:31:40.620  5471  5647 D Baresip Lib:  expire=42ms file=src/metric.c:
06-06 09:31:40.620  5471  5647 D Baresip Lib: 65
06-06 09:31:40.620  5471  5647 D Baresip Lib:   0x78fc621a98
06-06 09:31:40.620  5471  5647 D Baresip Lib: : th=0x789e1a8814 expire=58269
06-06 09:31:40.620  5471  5647 D Baresip Lib: ms file=src/sip/transp.c:309
06-06 09:31:40.620  5471  5647 D Baresip Lib:   0x78fc621798: th=0x
06-06 09:31:40.620  5471  5647 D Baresip Lib: 789e1a8814 expire=60414ms file=src/sip/transp.c
06-06 09:31:40.620  5471  5647 D Baresip Lib: :309
06-06 09:31:40.620  5471  5647 D Baresip Lib:   
06-06 09:31:40.620  5471  5647 D Baresip Lib: 0x78fc621918: th=0x
06-06 09:31:40.620  5471  5647 D Baresip Lib: 789e1a8814 expire=71247ms file=src/sip/transp.c
06-06 09:31:40.620  5471  5647 D Baresip Lib: :309
06-06 09:31:40.620  5471  5647 D Baresip Lib:   0x
06-06 09:31:40.620  5471  5647 D Baresip Lib: 78fe5b0078: th=0x789e1ab7c8 expire=
06-06 09:31:40.620  5471  5647 D Baresip Lib: 390670ms file=src/sipevent/subscribe.c:
06-06 09:31:40.620  5471  5647 D Baresip Lib: 141
06-06 09:31:40.620  5471  5647 D Baresip Lib:   0x
06-06 09:31:40.620  5471  5647 D Baresip Lib: 78fe5b07f8: th=0x789e1ab7c8 expire=391043ms file=src/sipevent/subscribe.c:141
06-06 09:31:40.620  5471  5647 D Baresip Lib:   0x78fc6d7a38: th=
06-06 09:31:40.620  5471  5647 D Baresip Lib: 0x789e1ad0b8 expire=570638ms file=
06-06 09:31:40.620  5471  5647 D Baresip Lib: src/sipreg/reg.c:263
06-06 09:31:40.620  5471  5647 D Baresip Lib:   
06-06 09:31:40.620  5471  5647 D Baresip Lib: 0x78fc6d7c38: th=0x
06-06 09:31:40.620  5471  5647 D Baresip Lib: 789e1ad0b8 expire=570895ms file=
06-06 09:31:40.620  5471  5647 D Baresip Lib: src/sipreg/reg.c:263
06-06 09:31:40.620  5471  5647 D Baresip Lib:   0x
06-06 09:31:40.620  5471  5647 D Baresip Lib: 78fc6d7d38: th=0x789e1ad0b8
06-06 09:31:40.620  5471  5647 D Baresip Lib:  expire=571046ms file=src/sipreg/reg.c:
06-06 09:31:40.620  5471  5647 D Baresip Lib: 263
06-06 09:31:40.620  5471  5647 D Baresip Lib:   0x
06-06 09:31:40.620  5471  5647 D Baresip Lib: 7895be5a38: th=0x789e1ad0b8
06-06 09:31:40.620  5471  5647 D Baresip Lib:  expire=631034ms file=src/sipreg/reg.c:
06-06 09:31:40.620  5471  5647 D Baresip Lib: 263
06-06 09:31:40.620  5471  5647 D Baresip Lib:   0x
06-06 09:31:40.620  5471  5647 D Baresip Lib: 78fe5fe950: th=0x789e1a90f8 expire=
06-06 09:31:40.620  5471  5647 D Baresip Lib: 751046ms file=src/sip/transp.c:526
06-06 09:31:40.620  5471  5647 D Baresip Lib: 
06-06 09:31:40.620  5471  5647 D Baresip Lib:   0x78fc621a50: th=
06-06 09:31:40.620  5471  5647 D Baresip Lib: 0x789e1a90f8 expire=849043
06-06 09:31:40.620  5471  5647 D Baresip Lib: ms file=src/sip/transp.c:474
06-06 09:31:40.620  5471  5647 D Baresip Lib:   0x78fc6218d0: th=0x
06-06 09:31:40.620  5471  5647 D Baresip Lib: 789e1a90f8 expire=856956ms file=src/sip/transp.c
06-06 09:31:40.620  5471  5647 D Baresip Lib: :474
06-06 09:31:40.620  5471  5647 D Baresip Lib:   
06-06 09:31:40.620  5471  5647 D Baresip Lib: 0x78fc6afd10: th=0x789e1c7c08
06-06 09:31:40.620  5471  5647 D Baresip Lib:  expire=859583ms file=src/dns/client.c:350
06-06 09:31:40.620  5471  5647 D Baresip Lib: 
06-06 09:31:40.620  5471  5647 D Baresip Lib:   0x78fc6afed0
06-06 09:31:40.620  5471  5647 D Baresip Lib: : th=0x789e1c7c08 expire=
06-06 09:31:40.620  5471  5647 D Baresip Lib: 859587ms file=src/dns/client.c:350
06-06 09:31:40.620  5471  5647 D Baresip Lib: 
06-06 09:31:40.620  5471  5647 D Baresip Lib:   0x78fc621750
06-06 09:31:40.620  5471  5647 D Baresip Lib: : th=0x789e1a90f8 expire=864336
06-06 09:31:40.620  5471  5647 D Baresip Lib: ms file=src/sip/transp.c:474
06-06 09:31:40.620  5471  5647 D Baresip Lib:   0x78fc6af990: th=
06-06 09:31:40.620  5471  5647 D Baresip Lib: 0x789e1c7c08 expire=880580
06-06 09:31:40.621  5471  5647 D Baresip Lib: ms file=src/dns/client.c:350
06-06 09:31:40.621  5471  5647 D Baresip Lib:   0x78fc6b0090: th=
06-06 09:31:40.621  5471  5647 D Baresip Lib: 0x789e1c7c08 expire=880587ms file=src/dns/client.c:
06-06 09:31:40.621  5471  5647 D Baresip Lib: 350
06-06 09:31:40.621  5471  5647 D Baresip Lib:   0x78fc6b0250
06-06 09:31:40.621  5471  5647 D Baresip Lib: : th=0x789e1c7c08 expire=
06-06 09:31:40.621  5471  5647 D Baresip Lib: 880591ms file=src/dns/client.c:350
06-06 09:31:40.621  5471  5647 D Baresip Lib: 
06-06 09:31:40.621  5471  5647 D Baresip Lib: 
06-06 09:31:40.621  5471  5647 D Baresip Lib: dnsc: --- QUESTION SECTION id: 34226 ---
06-06 09:31:40.621  5471  5647 D Baresip Lib: dnsc: box.tutpro.com.	IN
06-06 09:31:40.621  5471  5647 D Baresip Lib: 	AAAA
06-06 09:31:40.621  5471  5647 D Baresip Lib: 
06-06 09:31:40.621  5471  5647 D Baresip Lib: 
06-06 09:31:40.621  5471  5647 D Baresip Lib: dnsc: Timers (21
06-06 09:31:40.621  5471  5647 D Baresip Lib: ):
06-06 09:31:40.621  5471  5647 D Baresip Lib:   0x78fe55f028
06-06 09:31:40.621  5471  5647 D Baresip Lib: : th=0x789e1c7098 expire=
06-06 09:31:40.621  5471  5647 D Baresip Lib: 0ms file=src/dns/client.c:762
06-06 09:31:40.621  5471  5647 D Baresip Lib: 
06-06 09:31:40.621  5471  5647 D Baresip Lib:   0x78a0c93c38
06-06 09:31:40.621  5471  5647 D Baresip Lib: : th=0x789e188f34 expire=41
06-06 09:31:40.621  5471  5647 D Baresip Lib: ms file=src/metric.c:65
06-06 09:31:40.621  5471  5647 D Baresip Lib:   0x78a0c93d20: th=0x
06-06 09:31:40.621  5471  5647 D Baresip Lib: 789e188f34 expire=41ms file=
06-06 09:31:40.621  5471  5647 D Baresip Lib: src/metric.c:65
06-06 09:31:40.621  5471  5647 D Baresip Lib:   0x78fc621a98: th=0x
06-06 09:31:40.621  5471  5647 D Baresip Lib: 789e1a8814 expire=58268ms file=src/sip/transp.c
06-06 09:31:40.621  5471  5647 D Baresip Lib: :309
06-06 09:31:40.621  5471  5647 D Baresip Lib:   0x
06-06 09:31:40.621  5471  5647 D Baresip Lib: 78fc621798: th=0x789e1a8814 expire=60413
06-06 09:31:40.621  5471  5647 D Baresip Lib: ms file=src/sip/transp.c:309
06-06 09:31:40.621  5471  5647 D Baresip Lib:   0x78fc621918: th=0x
06-06 09:31:40.621  5471  5647 D Baresip Lib: 789e1a8814 expire=71246ms file=
06-06 09:31:40.621  5471  5647 D Baresip Lib: src/sip/transp.c:309
06-06 09:31:40.621  5471  5647 D Baresip Lib:   
06-06 09:31:40.621  5471  5647 D Baresip Lib: 0x78fe5b0078: th=0x
06-06 09:31:40.621  5471  5647 D Baresip Lib: 789e1ab7c8 expire=390669ms file=src/sipevent/subscribe.c
06-06 09:31:40.621  5471  5647 D Baresip Lib: :141
06-06 09:31:40.621  5471  5647 D Baresip Lib:   0x78fe5b07f8: th=
06-06 09:31:40.621  5471  5647 D Baresip Lib: 0x789e1ab7c8 expire=391042ms file=
06-06 09:31:40.621  5471  5647 D Baresip Lib: src/sipevent/subscribe.c:141
06-06 09:31:40.621  5471  5647 D Baresip Lib:   
06-06 09:31:40.621  5471  5647 D Baresip Lib: 0x78fc6d7a38: th=0x
06-06 09:31:40.621  5471  5647 D Baresip Lib: 789e1ad0b8 expire=570637ms file=src/sipreg/reg.c
06-06 09:31:40.621  5471  5647 D Baresip Lib: :263
06-06 09:31:40.621  5471  5647 D Baresip Lib:   
06-06 09:31:40.621  5471  5647 D Baresip Lib: 0x78fc6d7c38: th=0x789e1ad0b8
06-06 09:31:40.621  5471  5647 D Baresip Lib:  expire=570894ms file=src/sipreg/reg.c:263
06-06 09:31:40.621  5471  5647 D Baresip Lib: 
06-06 09:31:40.621  5471  5647 D Baresip Lib:   0x78fc6d7d38: th=
06-06 09:31:40.621  5471  5647 D Baresip Lib: 0x789e1ad0b8 expire=571045ms file=
06-06 09:31:40.621  5471  5647 D Baresip Lib: src/sipreg/reg.c:263
06-06 09:31:40.621  5471  5647 D Baresip Lib:   0x7895be5a38: th=0x
06-06 09:31:40.621  5471  5647 D Baresip Lib: 789e1ad0b8 expire=631033ms file=
06-06 09:31:40.621  5471  5647 D Baresip Lib: src/sipreg/reg.c:263
06-06 09:31:40.621  5471  5647 D Baresip Lib:   0x78fe5fe950: th=0x
06-06 09:31:40.621  5471  5647 D Baresip Lib: 789e1a90f8 expire=751045ms file=
06-06 09:31:40.621  5471  5647 D Baresip Lib: src/sip/transp.c:526
06-06 09:31:40.621  5471  5647 D Baresip Lib:   
06-06 09:31:40.621  5471  5647 D Baresip Lib: 0x78fc621a50: th=0x789e1a90f8
06-06 09:31:40.621  5471  5647 D Baresip Lib:  expire=849042ms file=src/sip/transp.c
06-06 09:31:40.621  5471  5647 D Baresip Lib: :474
06-06 09:31:40.621  5471  5647 D Baresip Lib:   0x
06-06 09:31:40.621  5471  5647 D Baresip Lib: 78fc6218d0: th=0x789e1a90f8 expire=
06-06 09:31:40.621  5471  5647 D Baresip Lib: 856955ms file=src/sip/transp.c:474
06-06 09:31:40.621  5471  5647 D Baresip Lib: 
06-06 09:31:40.621  5471  5647 D Baresip Lib:   0x78fc6afd10: th=
06-06 09:31:40.621  5471  5647 D Baresip Lib: 0x789e1c7c08 expire=859582
06-06 09:31:40.621  5471  5647 D Baresip Lib: ms file=src/dns/client.c:350
06-06 09:31:40.621  5471  5647 D Baresip Lib: 
06-06 09:31:40.621  5471  5647 D Baresip Lib:   0x78fc6afed0: th=
06-06 09:31:40.621  5471  5647 D Baresip Lib: 0x789e1c7c08 expire=859586
06-06 09:31:40.621  5471  5647 D Baresip Lib: ms file=src/dns/client.c:350
06-06 09:31:40.621  5471  5647 D Baresip Lib:   0x78fc621750: th=0x
06-06 09:31:40.621  5471  5647 D Baresip Lib: 789e1a90f8 expire=864335ms file=src/sip/transp.c
06-06 09:31:40.621  5471  5647 D Baresip Lib: :474
06-06 09:31:40.621  5471  5647 D Baresip Lib:   
06-06 09:31:40.621  5471  5647 D Baresip Lib: 0x78fc6af990: th=0x789e1c7c08
06-06 09:31:40.621  5471  5647 D Baresip Lib:  expire=880579ms file=src/dns/client.c:
06-06 09:31:40.621  5471  5647 D Baresip Lib: 350
06-06 09:31:40.621  5471  5647 D Baresip Lib:   0x
06-06 09:31:40.621  5471  5647 D Baresip Lib: 78fc6b0090: th=0x789e1c7c08 expire=
06-06 09:31:40.621  5471  5647 D Baresip Lib: 880586ms file=src/dns/client.c:350
06-06 09:31:40.621  5471  5647 D Baresip Lib: 
06-06 09:31:40.621  5471  5647 D Baresip Lib:   0x78fc6b0250
06-06 09:31:40.621  5471  5647 D Baresip Lib: : th=0x789e1c7c08 expire=880590
06-06 09:31:40.621  5471  5647 D Baresip Lib: ms file=src/dns/client.c:350
06-06 09:31:40.621  5471  5647 D Baresip Lib: 
06-06 09:31:40.621  5471  5471 D Baresip Lib: ua event (CALL_LOCAL_SDP) offer
06-06 09:32:38.921  5471  5647 D Baresip Lib: dnsc: --- ANSWER SECTION (CACHED) id: 33977 ---
06-06 09:32:38.921  5471  5647 D Baresip Lib: dnsc: box.tutpro.com.                 1009 IN   A       192.26.11
06-06 09:32:38.921  5471  5647 D Baresip Lib: 1.38
06-06 09:32:38.921  5471  5647 D Baresip Lib: dnsc: --- ANSWER SECTION (CACHED) id: 34226 ---
06-06 09:32:38.921  5471  5647 D Baresip Lib: dnsc: box.tutpro.com.                 1009 IN   AAAA    
06-06 09:32:38.921  5471  5647 D Baresip Lib: 2001:67c:224:666::26
06-06 09:32:38.921  5471  5647 D Baresip Lib: 
06-06 09:32:38.933  5471  5647 D Baresip Lib: 
06-06 09:32:38.935  5471  5647 D Baresip Lib: main: next timer: 
06-06 09:32:38.935  5471  5647 D Baresip Lib: 2101
06-06 09:32:38.936  5471  5647 D Baresip Lib:  ms
06-06 09:32:38.937  5471  5647 D Baresip Lib: 
06-06 09:32:39.034  5471  5647 D Baresip Lib: call: SIP Progress: 100 Trying (/)

@juha-h
Copy link
Contributor

juha-h commented Jun 6, 2022

Regarding re_thread_enter/leave calls, I double checked and every re_thread_enter() call is matched by re_thread_leave() call.

@sreimers
Copy link
Member Author

sreimers commented Jun 6, 2022

Ok thanks for your patience, maybe its another tmr that causes the delay, can you try this patch:

--- a/src/tmr/tmr.c
+++ b/src/tmr/tmr.c
@@ -27,12 +27,13 @@
 
 #define DEBUG_MODULE "tmr"
 #define DEBUG_LEVEL 5
+#define TMR_DEBUG 1
 #include <re_dbg.h>
 
 
 /** Timer values */
 enum {
-       MAX_BLOCKING = 500   /**< Maximum time spent in handler [ms] */
+       MAX_BLOCKING = 100   /**< Maximum time spent in handler [ms] */
 };
 
 extern struct list *tmrl_get(void);
@@ -57,7 +58,7 @@ static bool inspos_handler_0(struct le *le, void *arg)
 
 
 #if TMR_DEBUG
-static void call_handler(tmr_h *th, void *arg)
+static void call_handler(struct tmr *tmr, tmr_h *th, void *arg)
 {
        const uint64_t tick = tmr_jiffies();
        uint32_t diff;
@@ -68,8 +69,9 @@ static void call_handler(tmr_h *th, void *arg)
        diff = (uint32_t)(tmr_jiffies() - tick);
 
        if (diff > MAX_BLOCKING) {
-               DEBUG_WARNING("long async blocking: %u>%u ms (h=%p arg=%p)\n",
-                             diff, MAX_BLOCKING, th, arg);
+               DEBUG_WARNING(
+                       "long async blocking: %u>%u ms %s:%d (h=%p arg=%p)\n",
+                       diff, MAX_BLOCKING, tmr->file, tmr->line, th, arg);
        }
 }
 #endif
@@ -106,7 +108,7 @@ void tmr_poll(struct list *tmrl)
                        continue;
 
 #if TMR_DEBUG
-               call_handler(th, th_arg);
+               call_handler(tmr, th, th_arg);
 #else
                th(th_arg);
 #endif

@juha-h
Copy link
Contributor

juha-h commented Jun 6, 2022

I tried with the above patch and no warnings were produced (below) during the call nor before that from the start of the app. The delay is not always the same and can vary from a few seconds to tens of seconds.

6-06 10:52:13.866  7241  7241 D Baresip Lib: ua event (CALL_OUTGOING) sip:thetestcall@opensips.org
06-06 10:52:13.867  7241  7414 D Baresip Lib: call: connecting to 'sip:thetestcall@opensips.org'..
06-06 10:52:13.952  7241  7414 D Baresip Lib: dnsc: --- QUESTION SECTION id: 23717 ---
06-06 10:52:13.952  7241  7414 D Baresip Lib: dnsc: box.tutpro.com.	IN	A
06-06 10:52:13.952  7241  7414 D Baresip Lib: dnsc: Timers (21):
06-06 10:52:13.952  7241  7414 D Baresip Lib:   0x78fe566028: t
06-06 10:52:13.952  7241  7414 D Baresip Lib: h=0x789e1bd0a4 expire=0ms file=src/dns/client.c:762
06-06 10:52:13.952  7241  7414 D Baresip Lib:   0x78fdc28db8: th=0x789e17ef40 expire=14ms file=src/metric.c:65
06-06 10:52:13.952  7241  7414 D Baresip Lib:   0x78fdc2
06-06 10:52:13.952  7241  7414 D Baresip Lib: 8ea0: th=0x789e17ef40 expire=14ms file=src/metric.c:65
06-06 10:52:13.952  7241  7414 D Baresip Lib:   0x78fc621918: th=0x789e19e820 expire=80317ms file=src/sip/transp.c:309
06-06 10:52:13.952  7241  7414 D Baresip Lib: 
06-06 10:52:13.952  7241  7414 D Baresip Lib:   0x78fc621798: th=0x789e19e820 expire=92492ms file=src/sip/transp.c:309
06-06 10:52:13.952  7241  7414 D Baresip Lib:   0x78fc621a98: th=0x789e19e820 expire=103471ms file=
06-06 10:52:13.952  7241  7414 D Baresip Lib: src/sip/transp.c:309
06-06 10:52:13.952  7241  7414 D Baresip Lib:   0x78fe5b4078: th=0x789e1a17d4 expire=416902ms file=src/sipevent/subscribe.c:141
06-06 10:52:13.952  7241  7414 D Baresip Lib:   0x78fe5b47f8: th=0x789
06-06 10:52:13.952  7241  7414 D Baresip Lib: e1a17d4 expire=417253ms file=src/sipevent/subscribe.c:141
06-06 10:52:13.952  7241  7414 D Baresip Lib:   0x78fc6ebe38: th=0x789e1a30c4 expire=596843ms file=src/sipreg/reg.c
06-06 10:52:13.952  7241  7414 D Baresip Lib: :263
06-06 10:52:13.952  7241  7414 D Baresip Lib:   0x78fc6ebf38: th=0x789e1a30c4 expire=597128ms file=src/sipreg/reg.c:263
06-06 10:52:13.952  7241  7414 D Baresip Lib:   0x78fe5b1038: th=0x789e1a30c4 expire=597138ms 
06-06 10:52:13.952  7241  7414 D Baresip Lib: file=src/sipreg/reg.c:263
06-06 10:52:13.952  7241  7414 D Baresip Lib:   0x78fe5b1138: th=0x789e1a30c4 expire=597248ms file=src/sipreg/reg.c:263
06-06 10:52:13.952  7241  7414 D Baresip Lib:   0x78fc6b0090: th=0x789e1b
06-06 10:52:13.953  7241  7414 D Baresip Lib: dc14 expire=695778ms file=src/dns/client.c:350
06-06 10:52:13.953  7241  7414 D Baresip Lib:   0x78fc6b0790: th=0x789e1bdc14 expire=695785ms file=src/dns/client.c:350
06-06 10:52:13.953  7241  7414 D Baresip Lib:   0x78
06-06 10:52:13.953  7241  7414 D Baresip Lib: fc6b0950: th=0x789e1bdc14 expire=695790ms file=src/dns/client.c:350
06-06 10:52:13.953  7241  7414 D Baresip Lib:   0x78fe605950: th=0x789e19f104 expire=777248ms file=src/si
06-06 10:52:13.953  7241  7414 D Baresip Lib: p/transp.c:526
06-06 10:52:13.953  7241  7414 D Baresip Lib:   0x78fc6218d0: th=0x789e19f104 expire=882215ms file=src/sip/transp.c:474
06-06 10:52:13.953  7241  7414 D Baresip Lib:   0x78fc621750: th=0x789e19f104 expire
06-06 10:52:13.953  7241  7414 D Baresip Lib: =882698ms file=src/sip/transp.c:474
06-06 10:52:13.953  7241  7414 D Baresip Lib:   0x78fc621a50: th=0x789e19f104 expire=889570ms file=src/sip/transp.c:474
06-06 10:52:13.953  7241  7414 D Baresip Lib:   0x78a0819a90: t
06-06 10:52:13.953  7241  7414 D Baresip Lib: h=0x789e1bdc14 expire=1756937ms file=src/dns/client.c:350
06-06 10:52:13.953  7241  7414 D Baresip Lib:   0x78a0816d10: th=0x789e1bdc14 expire=1756943ms file=src/dns/client.
06-06 10:52:13.953  7241  7414 D Baresip Lib: c:350
06-06 10:52:13.953  7241  7414 D Baresip Lib: dnsc: --- QUESTION SECTION id: 12896 ---
06-06 10:52:13.953  7241  7414 D Baresip Lib: dnsc: box.tutpro.com.	IN	AAAA
06-06 10:52:13.953  7241  7414 D Baresip Lib: dnsc: Timers (21):
06-06 10:52:13.953  7241  7414 D Baresip Lib:   0x
06-06 10:52:13.953  7241  7414 D Baresip Lib: 78fe566028: th=0x789e1bd0a4 expire=0ms file=src/dns/client.c:762
06-06 10:52:13.953  7241  7414 D Baresip Lib:   0x78fdc28db8: th=0x789e17ef40 expire=13ms file=src/metric.c:
06-06 10:52:13.953  7241  7414 D Baresip Lib: 65
06-06 10:52:13.953  7241  7414 D Baresip Lib:   0x78fdc28ea0: th=0x789e17ef40 expire=13ms file=src/metric.c:65
06-06 10:52:13.953  7241  7414 D Baresip Lib:   0x78fc621918: th=0x789e19e820 expire=80316ms file=src/sip
06-06 10:52:13.953  7241  7414 D Baresip Lib: /transp.c:309
06-06 10:52:13.953  7241  7414 D Baresip Lib:   0x78fc621798: th=0x789e19e820 expire=92491ms file=src/sip/transp.c:309
06-06 10:52:13.953  7241  7414 D Baresip Lib:   0x78fc621a98: th=0x789e19e820 expire=1
06-06 10:52:13.953  7241  7414 D Baresip Lib: 03470ms file=src/sip/transp.c:309
06-06 10:52:13.953  7241  7414 D Baresip Lib:   0x78fe5b4078: th=0x789e1a17d4 expire=416901ms file=src/sipevent/subscribe.c:141
06-06 10:52:13.953  7241  7414 D Baresip Lib:   0x78fe5b4
06-06 10:52:13.953  7241  7414 D Baresip Lib: 7f8: th=0x789e1a17d4 expire=417252ms file=src/sipevent/subscribe.c:141
06-06 10:52:13.953  7241  7414 D Baresip Lib:   0x78fc6ebe38: th=0x789e1a30c4 expire=596842ms file=src
06-06 10:52:13.953  7241  7414 D Baresip Lib: /sipreg/reg.c:263
06-06 10:52:13.953  7241  7414 D Baresip Lib:   0x78fc6ebf38: th=0x789e1a30c4 expire=597127ms file=src/sipreg/reg.c:263
06-06 10:52:13.953  7241  7414 D Baresip Lib:   0x78fe5b1038: th=0x789e1a30c4 exp
06-06 10:52:13.953  7241  7414 D Baresip Lib: ire=597137ms file=src/sipreg/reg.c:263
06-06 10:52:13.953  7241  7414 D Baresip Lib:   0x78fe5b1138: th=0x789e1a30c4 expire=597247ms file=src/sipreg/reg.c:263
06-06 10:52:13.953  7241  7414 D Baresip Lib:   0x78fc6b0090
06-06 10:52:13.953  7241  7414 D Baresip Lib: : th=0x789e1bdc14 expire=695777ms file=src/dns/client.c:350
06-06 10:52:13.953  7241  7414 D Baresip Lib:   0x78fc6b0790: th=0x789e1bdc14 expire=695784ms file=src/dns/client
06-06 10:52:13.953  7241  7241 D Baresip Lib: ua event (CALL_LOCAL_SDP) offer
06-06 10:52:13.953  7241  7414 D Baresip Lib: .c:350
06-06 10:52:13.953  7241  7414 D Baresip Lib:   0x78fc6b0950: th=0x789e1bdc14 expire=695789ms file=src/dns/client.c:350
06-06 10:52:13.953  7241  7414 D Baresip Lib:   0x78fe605950: th=0x789e19f104 expire=777247m
06-06 10:52:13.953  7241  7414 D Baresip Lib: s file=src/sip/transp.c:526
06-06 10:52:13.953  7241  7414 D Baresip Lib:   0x78fc6218d0: th=0x789e19f104 expire=882214ms file=src/sip/transp.c:474
06-06 10:52:13.953  7241  7414 D Baresip Lib:   0x78fc621750: th=0x789e
06-06 10:52:13.953  7241  7414 D Baresip Lib: 19f104 expire=882697ms file=src/sip/transp.c:474
06-06 10:52:13.953  7241  7414 D Baresip Lib:   0x78fc621a50: th=0x789e19f104 expire=889569ms file=src/sip/transp.c:474
06-06 10:52:13.953  7241  7414 D Baresip Lib:   0x
06-06 10:52:13.953  7241  7414 D Baresip Lib: 78a0819a90: th=0x789e1bdc14 expire=1756936ms file=src/dns/client.c:350
06-06 10:52:13.953  7241  7414 D Baresip Lib:   0x78a0816d10: th=0x789e1bdc14 expire=1756942ms file=sr
06-06 10:52:13.953  7241  7414 D Baresip Lib: c/dns/client.c:350
06-06 10:52:13.953  7241  7414 D Baresip Lib: 
06-06 10:53:34.353  7241  7414 D Baresip Lib: dnsc: --- ANSWER SECTION (CACHED) id: 23717 ---
06-06 10:53:34.353  7241  7414 D Baresip Lib: dnsc: box.tutpro.com.                 3600 IN   A       192.26.11
06-06 10:53:34.353  7241  7414 D Baresip Lib: 1.38
06-06 10:53:34.353  7241  7414 D Baresip Lib: dnsc: --- ANSWER SECTION (CACHED) id: 12896 ---
06-06 10:53:34.353  7241  7414 D Baresip Lib: dnsc: box.tutpro.com.                 3600 IN   AAAA    
06-06 10:53:34.353  7241  7414 D Baresip Lib: 2001:67c:224:666::26
06-06 10:53:34.353  7241  7414 D Baresip Lib: 
06-06 10:53:34.366  7241  7414 D Baresip Lib: 
06-06 10:53:34.367  7241  7414 D Baresip Lib: main: next timer: 
06-06 10:53:34.368  7241  7414 D Baresip Lib: 3000
06-06 10:53:34.369  7241  7414 D Baresip Lib:  ms
06-06 10:53:34.370  7241  7414 D Baresip Lib: 
06-06 10:53:34.639  7241  7414 D Baresip Lib: call: SIP Progress: 100 Trying (/)

@sreimers
Copy link
Member Author

sreimers commented Jun 6, 2022

Ok that is really strange. Since next timer (from fd_poll) is logged after the cached answer, it looks like it got stuck in tmr_poll, but if there is no long async blocking logged, I'm clueless at the moment. I have to think about this.

@alfredh
Copy link
Contributor

alfredh commented Jun 6, 2022

hi,

please note that if you call tmr_start from a different thread and the thread running re_main,
it will not "wake up" the sleeping re_main (for example epoll).

in order to test this you can add a new dummy timer that is restarted
e.g. every 1 second. If the dns works with this and the delay is around 1 second,
then you will know that that is the case.

another test is to add a call to mqueue_send at the same time as the timer is started,
this will force the re_main to "wake up".

There is a patch somewhere that checks from which thread the fd_listen and tmr_start
is called, perhaps find it and apply it for local testing ?

@juha-h
Copy link
Contributor

juha-h commented Jun 6, 2022

Hope that I didn't miss anything in the patches. Below is diff that I have been using.

diff --git a/src/dns/client.c b/src/dns/client.c
index 88343a8..9959234 100644
--- a/src/dns/client.c
+++ b/src/dns/client.c
@@ -20,7 +20,7 @@
 
 
 #define DEBUG_MODULE "dnsc"
-#define DEBUG_LEVEL 5
+#define DEBUG_LEVEL 6
 #include <re_dbg.h>
 
 
@@ -761,6 +761,8 @@ static bool query_cache_handler(struct dns_query *q)
 
 	tmr_start(&q->dnsc->hdl_tmr, 0, hdl_tmr_cache, &q->dnsc->hdl_cache);
 
+	DEBUG_NOTICE("%H\n", tmr_debug);
+
 	return true;
 }
 
diff --git a/src/main/main.c b/src/main/main.c
index 023759e..f15fd01 100644
--- a/src/main/main.c
+++ b/src/main/main.c
@@ -695,7 +695,7 @@ static int fd_poll(struct re *re)
 	fd_set rfds, wfds, efds;
 #endif
 
-	DEBUG_INFO("next timer: %llu ms\n", to);
+	DEBUG_NOTICE("next timer: %llu ms\n", to);
 
 	/* Wait for I/O */
 	switch (re->method) {
diff --git a/src/tmr/tmr.c b/src/tmr/tmr.c
index 3ee28b9..2b4be50 100644
--- a/src/tmr/tmr.c
+++ b/src/tmr/tmr.c
@@ -27,12 +27,13 @@
 
 #define DEBUG_MODULE "tmr"
 #define DEBUG_LEVEL 5
+#define TMR_DEBUG 1
 #include <re_dbg.h>
 
 
 /** Timer values */
 enum {
-	MAX_BLOCKING = 500   /**< Maximum time spent in handler [ms] */
+	MAX_BLOCKING = 100   /**< Maximum time spent in handler [ms] */
 };
 
 extern struct list *tmrl_get(void);
@@ -57,7 +58,7 @@ static bool inspos_handler_0(struct le *le, void *arg)
 
 
 #if TMR_DEBUG
-static void call_handler(tmr_h *th, void *arg)
+static void call_handler(struct tmr *tmr, tmr_h *th, void *arg)
 {
 	const uint64_t tick = tmr_jiffies();
 	uint32_t diff;
@@ -68,8 +69,8 @@ static void call_handler(tmr_h *th, void *arg)
 	diff = (uint32_t)(tmr_jiffies() - tick);
 
 	if (diff > MAX_BLOCKING) {
-		DEBUG_WARNING("long async blocking: %u>%u ms (h=%p arg=%p)\n",
-			      diff, MAX_BLOCKING, th, arg);
+		DEBUG_WARNING("long async blocking: %u>%u ms %s:%d (h=%p arg=%p)\n",
+			      diff, MAX_BLOCKING, tmr->file, tmr->line, th, arg);
 	}
 }
 #endif
@@ -106,7 +107,7 @@ void tmr_poll(struct list *tmrl)
 			continue;
 
 #if TMR_DEBUG
-		call_handler(th, th_arg);
+		call_handler(tmr, th, th_arg);
 #else
 		th(th_arg);
 #endif

@juha-h
Copy link
Contributor

juha-h commented Jun 6, 2022 via email

wip-sync pushed a commit to NetBSD/pkgsrc-wip that referenced this pull request Jul 18, 2022
== [v2.5.0] - 2022-07-01

* av1: add doxygen comments by @alfredh in baresip/re#384
* rtp: add function to calc sequence number diff by @alfredh in baresip/re#385
* CI fixes by @sreimers in baresip/re#387
* trace: C11 mutex by @alfredh in baresip/re#390
* trace: init refactor by @sreimers in baresip/re#391
* jbuf: use C11 mutex by @alfredh in baresip/re#392
* av1: define and make AV1_AGGR_HDR_SIZE public by @alfredh in baresip/re#393
* main: add re_thread_check() for NON-RE thread calls by @sreimers in baresip/re#389
* cmake: add HAVE_SIGNAL on UNIX by @sreimers in baresip/re#394
* av1: add av1_obu_count() by @alfredh in baresip/re#395
* thread: add mtx_alloc by @sreimers in baresip/re#396
* rtp: C11 mutex by @alfredh in baresip/re#397
* lock: remove deprecated module by @alfredh in baresip/re#398
* Added sippreg_unregister API function by @juha-h in baresip/re#400
* av1 work by @alfredh in baresip/re#402
* rtp: add rtp_is_rtcp_packet() by @alfredh in baresip/re#405
* Fix mutex alloc destroy by @sreimers in baresip/re#406
* av1: minor fixes and doxygen comments by @alfredh in baresip/re#407
* rtp: Add support for RFC5104 PSFB FIR by @Lastique in baresip/re#408
* jbuf: Add drain method by @Lastique in baresip/re#409
* uag: add timestamps to SIP trace by @cspiel1 in baresip/re#412
* fmt/fmt_timestamp: some cleanup by @sreimers in baresip/re#413
* main: refactor libre_init and re_global handling by @sreimers in baresip/re#404
* main: Add support for external threads attaching/detaching re context by @Lastique in baresip/re#414
* mem: Fix formatting for nrefs and size. by @Lastique in baresip/re#415

---

== [v2.4.0] - 2022-06-01

== What's Changed
* ci: test centos -> fedora by @alfredh in baresip/re#340
* Tls bio opaque by @alfredh in baresip/re#341
* main: remove usage of crypto_set_id_callback() by @alfredh in baresip/re#342
* jbuf: in adaptive mode do not manipulate min buffer size by @cspiel1 in baresip/re#343
* av1 obu by @alfredh in baresip/re#345
* jbuf: improve adaptive mode by @cspiel1 in baresip/re#344
* av1 packetizer by @alfredh in baresip/re#346
* av1: depacketizer by @alfredh in baresip/re#347
* h265: move from rem to re by @alfredh in baresip/re#348
* jbuf: avoid reducing of wish size too early by @cspiel1 in baresip/re#349
* ci/build: add ubuntu 22.04 (beta) by @sreimers in baresip/re#351
* h264: move from rem to re by @alfredh in baresip/re#350
* add C11 thread, mutex and condition API by @sreimers in baresip/re#249
* thread: use pthread as default fallback by @sreimers in baresip/re#354
* mem: use new C11 mutex locking by @sreimers in baresip/re#352
* dbg: use C11 thread mutex by @sreimers in baresip/re#356
* thread: add thread-local storage functions by @sreimers in baresip/re#355
* main/openssl: cleanup by @sreimers in baresip/re#358
* cmake: sort warning flags by @alfredh in baresip/re#359
* doxygen: update comments by @alfredh in baresip/re#360
* main: use C11 thread mutex by @sreimers in baresip/re#357
* make: disable warning flag -Wdeclaration-after-statement by @alfredh in baresip/re#363
* cleanup pthread by @sreimers in baresip/re#362
* update doxygen comments by @alfredh in baresip/re#366
* ci/coverage: downgrade gcovr by @sreimers in baresip/re#365
* tls: print openssl error queue if accept failed by @alfredh in baresip/re#367
* main: fd_setsize -1 for RLIMIT_NOFILE value by @sreimers in baresip/re#368
* jbuf: flush on RTP timeout by @cspiel1 in baresip/re#370
* thread: add mtx_destroy by @sreimers in baresip/re#371
* dns: add query cache by @sreimers in baresip/re#369
* mem,btrace: fix struct alignment by @sreimers in baresip/re#372
* av1: change start flag to continuation flag (inverse) by @alfredh in baresip/re#375
* tmr: add tmr_start_dbg by @sreimers in baresip/re#373
* ice: rename to local pref by @alfredh in baresip/re#376
* tls: Switch from EVP_sha1() to EVP_sha256() when using it for X509_sign() by @robert-scheck in baresip/re#377

---

== [v2.3.0] - 2022-05-01

* cmake: use static build as default target (improves subdirectory usage) by @sreimers in baresip/re#311
* jbuf: fix RELEASE build with DEBUG_LEVEL 6 by @cspiel1 in baresip/re#313
* fmt/pl: use unsigned type before negation by @sreimers in baresip/re#312
* fmt/pl: rewrite negative handling (avoid undefined behavior) by @sreimers in baresip/re#314
* http/request: fix possbile null pointer dereference by @sreimers in baresip/re#316
* sdp: check sdp_bandwidth lower bound by @sreimers in baresip/re#317
* main: use re_sock_t by @sreimers in baresip/re#315
* ccheck: check all CMakeLists.txt files by @sreimers in baresip/re#320
* list: O(1) sorted insert if we expect append in most cases by @cspiel1 in baresip/re#318
* add pcp protocol by @alfredh in baresip/re#321
* cmake: define RELEASE for release builds by @alfredh in baresip/re#323
* Mem lock win32 by @alfredh in baresip/re#324
* pcp: fix win32 warning by @alfredh in baresip/re#325
* ci/msvc: treat all compiler warnings as errors by @sreimers in baresip/re#326
* cmake: add MSVC /W3 compile option by @sreimers in baresip/re#327
* cmake: add FreeBSD and OpenBSD by @sreimers in baresip/re#329
* md5: remove fallback implementation by @sreimers in baresip/re#328
* cmake: add runtime and development install components by @sreimers in baresip/re#330
* mem: remove low/high block size stats by @alfredh in baresip/re#331
* mem: add error about missing locking by @alfredh in baresip/re#332
* set TCP source port in Via and Contact header by @cspiel1 in baresip/re#334
* remove sys_rel_get and epoll_check by @alfredh in baresip/re#335
* support tls session reuse   by @fAuernigg in baresip/re#333
* rand: init only needed for libc rand by @alfredh in baresip/re#336
* tls: fix crash in debug warn msg by @fAuernigg in baresip/re#337
* mem: init g_memLock directly by @alfredh in baresip/re#339
* prepare for version 2.3.0 by @alfredh in baresip/re#338

---

== [v2.2.2] - 2022-04-09

* sha256: add wrapper by @alfredh in baresip/re#306
* workflow: upgrade to openssl 3.0.2 by @alfredh in baresip/re#305
* aubuf adaptive jitter buffer by @cspiel1 in baresip/re#303
* Improve WIN32 UDP socket handling by @sreimers in baresip/re#296
* tcp: remove tcp_conn_fd by @alfredh in baresip/re#308
* tcp: improve win32 socket and error handling by @sreimers in baresip/re#309

---

== [v2.2.1] - 2022-04-01

* cmake: add packaging by @sreimers in baresip/re#299
* sha: add sha 256 and 512 digest length OpenSSL compats by @sreimers in baresip/re#300
* main: use Winsock2.h by @sreimers in baresip/re#302
* cmake: for Android platform dont enable ifaddrs/getifaddrs by @alfredh in baresip/re#304
* sa/sa_is_loopback: check full IPv4 loopback range (127.0.0.0/8) by @sreimers in baresip/re#301

---

== [v2.2.0] - 2022-03-28

* tls: fix coverity defect by @alfredh in baresip/re#270
* http/client: read_file check ftell return value by @sreimers in baresip/re#272
* udp: fix coverity defect by @alfredh in baresip/re#271
* cmake: add detection of HAVE_ARC4RANDOM by @alfredh in baresip/re#269
* Fix coverity issues by @sreimers in baresip/re#273
* Support adding CRLs by @fAuernigg in baresip/re#274
* json/decode: fix possible out of bound access, if code changes by @sreimers in baresip/re#275
* tls/tls_add_crlpem: use const by @sreimers in baresip/re#276
* udp: fix coverity defect by @alfredh in baresip/re#279
* dns: fix Coverity Defect by @alfredh in baresip/re#278
* tls: use const pointer for tls_add_capem() by @cspiel1 in baresip/re#277
* srtp/srtcp: add sanity check for rtcp->tag_len by @sreimers in baresip/re#280
* shim: new module from rew by @alfredh in baresip/re#282
* Trice module by @alfredh in baresip/re#283
* retest trice by @alfredh in baresip/re#284
* Add try_into conversion helper and drop gcc 4.8 support by @sreimers in baresip/re#286
* rtp: fix signed/unsigned warning on WIN32 by @alfredh in baresip/re#287
* fix build error on openbsd arm64 (raspberry pi) by @jimying in baresip/re#290
* cmake: disable C extensions (like make) by @sreimers in baresip/re#292
* fmt: add bool decode from struct pl by @cspiel1 in baresip/re#293
* sdp: a utility function for decoding SDP direction by @cspiel1 in baresip/re#294
* sa/sa_ntop: check inet_ntop() return value by @sreimers in baresip/re#295
* sa_pton: use sa_addrinfo for interface suffix by @alfredh in baresip/re#297

=== New Contributors
* @jimying made their first contribution in baresip/re#290

---

== [v2.1.1] - 2022-03-12

=== Fixes

* mk: fix ABI versioning [#268](baresip/re#268)

---

== [v2.1.0] - 2022-03-11

=== What's Changed
* Tls sipcert per acc by @cHuberCoffee in baresip/re#96
* ToS for video and sip by @cspiel1 in baresip/re#98
* sdp: in media_decode() reset rdir if port is zero by @cspiel1 in baresip/re#99
* mk/re: add variable length array (-Wvla) compiler warning by @sreimers in baresip/re#100
* Macos openssl by @sreimers in baresip/re#105
* pkg-config version check by @sreimers in baresip/re#107
* sa: add setter and getter for scope id by @cspiel1 in baresip/re#108
* net: in net_dst_source_addr_get() make parameter dst const by @cspiel1 in baresip/re#109
* Avoid 'ISO C90 forbids mixed declarations and code' warnings by @juha-h in baresip/re#112
* SIP redirect callbackfunction by @cHuberCoffee in baresip/re#111
* add secure websocket tls context by @sreimers in baresip/re#113
* fmt: add string to bool function by @cspiel1 in baresip/re#115
* fix clang analyze warnings by @sreimers in baresip/re#114
* fmt: support different separators for parameter parsing by @cspiel1 in baresip/re#117
* Refactor inet_ntop and inet_pton by @sreimers in baresip/re#118
* add essential fields check by @I-mpossible in baresip/re#119
* sa: add support for interface suffix for IPv6ll by @cspiel1 in baresip/re#116
* net: fix net_if_getname IPv6 support by @sreimers in baresip/re#120
* udp: add udp_recv_helper by @alfredh in baresip/re#122
* sa: fix build for old systems by @cspiel1 in baresip/re#121
* sa/addrinfo: fix openbsd (drop AI_V4MAPPED flag) by @sreimers in baresip/re#125
* ci/codeql: add scan-build by @sreimers in baresip/re#128
* Fixed debian changelog version by @juha-h in baresip/re#129
* IPv6 link local support by @cspiel1 in baresip/re#106
* sip: add fallback transport for transp_find() by @cspiel1 in baresip/re#132
* SIP default protocol by @cspiel1 in baresip/re#131
* remove orphaned files by @viordash in baresip/re#136
* outgoing calls early callid by @cspiel1 in baresip/re#135
* sip: fix possible "???" dns srv queries by skipping lines without srvid by @cHuberCoffee in baresip/re#133
* odict: hide struct odict_entry by @sreimers in baresip/re#130
* tls: add keylogger callback function by @cHuberCoffee in baresip/re#140
* http/client: support other auth token types besides bearer by @fAuernigg in baresip/re#142
* tls: fix client certificate replacement by @cHuberCoffee in baresip/re#145
* http/client: support dns ipv6 by @fAuernigg in baresip/re#141
* rtp: add payload-type helper by @alfredh in baresip/re#148
* sip: check consistency between CSeq method and that of request line by @I-mpossible in baresip/re#146
* Fix win32 by @viordash in baresip/re#149
* fix warnings from PVS-Studio C++ static analyzer by @viordash in baresip/re#150
* RTP inbound telephone events should not lead to packet loss by @cspiel1 in baresip/re#151
* support inet6 by default in Win32 project by @viordash in baresip/re#154
* sdp: differentiate between media line disabled or rejected by @cHuberCoffee in baresip/re#134
* move network check to module by @cspiel1 in baresip/re#152
* odict: move odict_compare from retest to re by @fAuernigg in baresip/re#153
* sip: reuse transport protocol of first request in dialog (#143) by @cspiel1 in baresip/re#144
* json: fix parsing json containing only single value by @fAuernigg in baresip/re#155
* ice: fix checklist by @alfredh in baresip/re#156
* mk: add compile_commands.json (clang only) by @sreimers in baresip/re#157
* sdp: debug print session and media direction by @cspiel1 in baresip/re#158
* add btrace module (linux/unix only) by @sreimers in baresip/re#160
* mk: add CC_TEST header check by @sreimers in baresip/re#162
* init dst address by @cspiel1 in baresip/re#164
* ice: check if candpair exist before adding by @alfredh in baresip/re#165
* mk: add CC_TEST cache by @sreimers in baresip/re#163
* btrace: use HAVE_EXECINFO by @sreimers in baresip/re#166
* Coverity by @sreimers in baresip/re#170
* icem: remove dead code (found by coverity 240639) by @sreimers in baresip/re#171
* hash: switch to simpler "fast algorithm" by @ydroneaud in baresip/re#173
* dns: fix dnsc_alloc with IPv6 disabled by @sreimers in baresip/re#174
* mk: deprecate HAVE_INET6 by @sreimers in baresip/re#175
* Fix for btrace print for memory leaks by @cspiel1 in baresip/re#177
* set sdp laddr to SIP src address by @cspiel1 in baresip/re#172
* sdp: include all media formats in SDP offer by @cHuberCoffee in baresip/re#176
* ci: add centos 7 build test by @sreimers in baresip/re#179
* sip: move sip_auth_encode to public api for easier testing by @sreimers in baresip/re#181
* sipsess: do not call desc handler on shutdown by @cspiel1 in baresip/re#182
* stream flush rtp socket by @cspiel1 in baresip/re#185
* ci: fix macos openssl build by @sreimers in baresip/re#188
* http: HTTP Host header conform to RFC for IPv6 addresses by @cspiel1 in baresip/re#189
* Increased debian compatibility level from 9 to 10 by @juha-h in baresip/re#192
* mk: move darwin dns LFLAGS to re.mk (fixes static builds) by @sreimers in baresip/re#193
* build infrastructure: silent and verbose modes by @abrodkin in baresip/re#194
* mk: use posix regex for sed CC major version detection by @sreimers in baresip/re#195
* dns: fix parse_resolv_conf for OpenBSD by @sreimers in baresip/re#196
* sip: add optional TCP source port by @cspiel1 in baresip/re#198
* ci: add mingw build and test by @sreimers in baresip/re#199
* net: remove net_hostaddr by @sreimers in baresip/re#200
* ci/centos7: add openssl by @sreimers in baresip/re#203
* hmac: use HMAC() api (fixes OpenSSL 3.0 deprecations) by @sreimers in baresip/re#202
* md5: use EVP_Digest for newer openssl versions by @sreimers in baresip/re#204
* sha: add new sha1() api by @sreimers in baresip/re#205
* OpenSSL 3.0 by @sreimers in baresip/re#206
* udp: add win32 qos support by @sreimers in baresip/re#186
* ci/mingw: fix dependency checkout by @sreimers in baresip/re#207
* ice: remove ice_mode by @alfredh in baresip/re#147
* Codeql security by @sreimers in baresip/re#208
* aubuf insert auframes sorted by @cspiel1 in baresip/re#209
* ci: add valgrind by @sreimers in baresip/re#214
* tls: remove code for openssl 0.9.5 by @alfredh in baresip/re#215
* ice: remove unused file by @alfredh in baresip/re#217
* main: remove obsolete OPENWRT epoll check by @alfredh in baresip/re#218
* dns,http,sa: fix HAVE_INET6 off warnings by @sreimers in baresip/re#219
* preliminary support for cmake by @alfredh in baresip/re#220
* make,cmake: set SOVERSION to major version by @sreimers in baresip/re#221
* mk: remove MSVC project files, use cmake instead by @alfredh in baresip/re#223
* natbd: remove module (deprecated) by @alfredh in baresip/re#225
* sha: remove backup implementation by @alfredh in baresip/re#224
* sha,hmac: use Apple CommonCrypto if defined by @alfredh in baresip/re#226
* stun: add stun_generate_tid by @alfredh in baresip/re#227
* add cmakelint by @sreimers in baresip/re#228
* Cmake version by @alfredh in baresip/re#229
* cmake: add option to enable/disable rtmp module by @alfredh in baresip/re#230
* lock: use rwlock by default by @sreimers in baresip/re#232
* cmake: fixes for MSVC 16 by @alfredh in baresip/re#233
* json: fix win32 warnings by @alfredh in baresip/re#234
* ci: add cmake build by @sreimers in baresip/re#222
* mqueue: fix win32 warnings by @alfredh in baresip/re#235
* tcp: fix win32 warnings by @alfredh in baresip/re#236
* cmake: fix target_link_libraries for win32 by @alfredh in baresip/re#238
* stun: fix win32 warnings by @alfredh in baresip/re#237
* udp: fix win32 warnings by @alfredh in baresip/re#239
* tls: fix win32 warnings by @alfredh in baresip/re#241
* remove HAVE_INTTYPES_H by @alfredh in baresip/re#231
* udp: fix win32 warnings by @alfredh in baresip/re#242
* cmake: minor fixes by @alfredh in baresip/re#244
* cmake: fix MSVC ninja by @sreimers in baresip/re#243
* tcp: fix win32 warnings by @alfredh in baresip/re#245
* udp: fix win32 msvc warnings by @sreimers in baresip/re#246
* rtmp: fix win32 warning by @sreimers in baresip/re#247
* bfcp: fix win32 warning by @sreimers in baresip/re#248
* tls: fix libressl 3.5 by @sreimers in baresip/re#250
* fix coverity scan warnings by @sreimers in baresip/re#251
* Allow hanging up call that has not been ACKed yet by @juha-h in baresip/re#252
* mk,cmake: add backtrace support and fix linking on OpenBSD by @sreimers in baresip/re#254
* github: add CMake and Windows workflow by @alfredh in baresip/re#255
* Windows (VS 2022/Ninja) by @sreimers in baresip/re#257
* cmake: fixes for Android by @alfredh in baresip/re#258
* tmr: reuse tmr_jiffies_usec by @alfredh in baresip/re#259
* trace: use gettid as thread_id on linux by @sreimers in baresip/re#213
* tmr: use CLOCK_MONOTONIC_RAW if defined by @alfredh in baresip/re#260
* add atomic support by @sreimers in baresip/re#261
* Sonarcloud by @sreimers in baresip/re#262
* sip: fix gcc 6.3.0 warning for logical expression (#256) by @cspiel1 in baresip/re#263
* add transport-cc rtcp feedback support by @fippo in baresip/re#264

=== New Contributors
* @I-mpossible made their first contribution in baresip/re#119
* @viordash made their first contribution in baresip/re#136
* @ydroneaud made their first contribution in baresip/re#173
* @abrodkin made their first contribution in baresip/re#194
@sreimers
Copy link
Member Author

sreimers commented Aug 23, 2022

@juha-h can you verify if this fixes your DNS Cache timer problems: 75001ed (needs recent main version)

@juha-h
Copy link
Contributor

juha-h commented Aug 23, 2022

No it didn't. Invite delay is still very long if I have DNS name in my outbound proxy URI.

@sreimers
Copy link
Member Author

sreimers commented Aug 23, 2022

Forgot to mention, you need to initialize (re_thread_async_init) the new thread worker first, like here:

baresip/baresip@d743e91

@juha-h
Copy link
Contributor

juha-h commented Aug 23, 2022

Looks like it helped in some cases, for example, calls via my outbound proxy now work fast, but when I try to call e.g. sip2sip.info directly w/o outbound proxy, the call times out.

@juha-h
Copy link
Contributor

juha-h commented Aug 23, 2022

Perhaps there is some problem with sip2sip.info, since the call times out also when DNS cache is off. However, call to sip2sip.info via my outbound proxy works fine. Calling thetestcall@opensips.org works fine when cache is on.

Are there some other benefits when re_thread_async is initialized?

@sreimers
Copy link
Member Author

there will probably be some functions in the future that depend on it (currently only async gettaddrinfo).

@juha-h
Copy link
Contributor

juha-h commented Aug 23, 2022

I made more tests with dns cache on and noticed that there is INVITE delay to sip2sip.info only when tls is used. So the delay is not DNS query related.

@juha-h
Copy link
Contributor

juha-h commented Oct 11, 2022 via email

@cspiel1
Copy link
Collaborator

cspiel1 commented Oct 11, 2022

But this has nothing to do with the DNS query cache. Right?

Why should we set 20% as default? 90% should be okay.
Our testers found that in some situations (TLS) the expiry parameter in the Contact header of the response to the REGISTER is not used correctly. I suggest that the parsing of the contact header does not work correctly. But had no time so far to verify this.

@juha-h
Copy link
Contributor

juha-h commented Oct 11, 2022

My comment was done long ago via email and now appeared (like many others). No, nothing to do with DNS query cache and recently I removed the above hack. It is not needed anymore (don't know why). I have ;regint=900 and have been following registrations in the registrar syslog. I have not found any misses.

BUT one thing I did notice from the logs: my registrar removes registration if tcp or tls connection to the UA gets closed. When baresip then reconnects, it does not re-REGISTER automatically after that, but waits for regint to expire.

@juha-h
Copy link
Contributor

juha-h commented Oct 11, 2022

Is it possible via some API function to dump contents of DNS cache?

@sreimers
Copy link
Member Author

Is it possible via some API function to dump contents of DNS cache?

At the moment not. If I have some spare time I can add one, in the meantime maybe dnsc debug mode helps:

--- a/src/dns/client.c
+++ b/src/dns/client.c
@@ -20,7 +20,7 @@
 
 
 #define DEBUG_MODULE "dnsc"
-#define DEBUG_LEVEL 5
+#define DEBUG_LEVEL 6
 #include <re_dbg.h>

You should see all DNS queries and answers, for cached answers "ANSWER SECTION (CACHED)" is printed.

@juha-h
Copy link
Contributor

juha-h commented Oct 12, 2022 via email

@sreimers
Copy link
Member Author

sreimers commented Oct 12, 2022

But only if you use dns_getaddrinfo, otherwise baresip directly use the configured dns_server.

@juha-h
Copy link
Contributor

juha-h commented Oct 12, 2022

I have not configured any dns_server. It is not possible to do in recent Android versions. For security reasons, apps have to use the dns servers provided by the OS.

@juha-h
Copy link
Contributor

juha-h commented Oct 12, 2022

I'll turn on dns_getaddrinfo in my Android app for testing what the effect is (if any).

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants