### CANCEL msg results in "500 cancel error" because of "duplicate From header" error
<!-- Explain what you did, what you expected to happen, and what actually happened. -->
Cancelling a call before it's answered sometimes results in a "500 cancel error" response and the far end not getting a cancel msg. The from header seems to be wrongly detected as being duplicated. This issue does not exist in version 5.2.8 or 5.1.10, does exist in 5.3.7 and 5.4.2.
From header from CANCEL that generates the error
``` f:"user 1002"sip:+1002@bf96cc.domain.com;tag=8FUg427jU6pva ```
From header from CANCEL that works fine
``` f:"Reseda Ca"sip:+18185144209@bf96cc.domain.com;tag=cm0KBFB1Fag7r ```
#### Log Messages
<!-- Check the syslog file and if there are relevant log messages printed by Kamailio, add them next, or attach to issue, or provide a link to download them (e.g., to a pastebin site). -->
``` Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg(): SIP Request: Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: <core> [core/parser/msg_parser.c:612]: parse_msg(): method: <CANCEL> Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg(): uri: sip:john.webrtc@bf96cc.domain.com Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg(): version: <SIP/2.0> Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 235, <rport> = <n/a>; state=6 Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKSg9eBr2tSDU5c>; state=16 Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5 Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: <core> [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=2 Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: <core> [core/parser/msg_parser.c:500]: parse_headers(): this is the first via Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=10 Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <t> [41]; uri=[sip:john.webrtc@bf96cc.domain.com] Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: <core> [core/parser/msg_parser.c:174]: get_hdr_field(): to body (41)[sip:john.webrtc@bf96cc.domain.com#015#012], to tag (0)[] Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <28924918> <CANCEL> Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: <core> [core/receive.c:319]: receive_msg(): --- received sip message - request - call-id: [39d19e18-afa6-1239-1dba-ea02c604123e] - cseq: [28924918 CANCEL] Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: <core> [core/parser/msg_parser.c:185]: get_hdr_field(): content_length=0 Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: {1 28924918 CANCEL 39d19e18-afa6-1239-1dba-ea02c604123e} <core> [core/receive.c:379]: receive_msg(): preparing to run routing scripts... Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: {1 28924918 CANCEL 39d19e18-afa6-1239-1dba-ea02c604123e} pv [pv_core.c:1073]: pv_get_useragent(): no User-Agent header Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: {1 28924918 CANCEL 39d19e18-afa6-1239-1dba-ea02c604123e} maxfwd [mf_funcs.c:74]: is_maxfwd_present(): value = 68 Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: {1 28924918 CANCEL 39d19e18-afa6-1239-1dba-ea02c604123e} tm [t_lookup.c:727]: t_lookupOriginalT(): searching on hash entry 19365 Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: {1 28924918 CANCEL 39d19e18-afa6-1239-1dba-ea02c604123e} tm [t_lookup.c:439]: matching_3261(): RFC3261 transaction matched, tid=Sg9eBr2tSDU5c Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: {1 28924918 CANCEL 39d19e18-afa6-1239-1dba-ea02c604123e} tm [t_lookup.c:823]: t_lookupOriginalT(): canceled transaction found (0x7f742bb6d000)! Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: {1 28924918 CANCEL 39d19e18-afa6-1239-1dba-ea02c604123e} tm [t_lookup.c:826]: t_lookupOriginalT(): found - lookup completed Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: {1 28924918 CANCEL 39d19e18-afa6-1239-1dba-ea02c604123e} tm [tm.c:1220]: ki_t_lookup_cancel_flags(): lookup_original: t_lookupOriginalT returned: 0x7f742bb6d000 Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: {1 28924918 CANCEL 39d19e18-afa6-1239-1dba-ea02c604123e} tm [t_lookup.c:1328]: t_newtran(): msg (0x7f74318090e8) id=97/2451 global id=96/2451 T start=0xffffffffffffffff Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: {1 28924918 CANCEL 39d19e18-afa6-1239-1dba-ea02c604123e} tm [t_lookup.c:497]: t_lookup_request(): start searching: hash=19365, isACK=0 Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: {1 28924918 CANCEL 39d19e18-afa6-1239-1dba-ea02c604123e} tm [t_lookup.c:455]: matching_3261(): RFC3261 transaction matching failed - via branch [z9hG4bKSg9eBr2tSDU5c] Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: {1 28924918 CANCEL 39d19e18-afa6-1239-1dba-ea02c604123e} tm [t_lookup.c:675]: t_lookup_request(): no transaction found Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: {1 28924918 CANCEL 39d19e18-afa6-1239-1dba-ea02c604123e} <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=N53jU220NtrFH Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: {1 28924918 CANCEL 39d19e18-afa6-1239-1dba-ea02c604123e} <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29 Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: {1 28924918 CANCEL 39d19e18-afa6-1239-1dba-ea02c604123e} <core> [core/crypto/md5utils.c:67]: MD5StringArray(): MD5 calculated: 3c5f13a67a8cbfe1028669836f4291d4 Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: {1 28924918 CANCEL 39d19e18-afa6-1239-1dba-ea02c604123e} tm [t_lookup.c:727]: t_lookupOriginalT(): searching on hash entry 19365 Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: {1 28924918 CANCEL 39d19e18-afa6-1239-1dba-ea02c604123e} tm [t_lookup.c:430]: matching_3261(): matched skip method - s:0x2 t:0x2 m:0x2 - continue searching Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: {1 28924918 CANCEL 39d19e18-afa6-1239-1dba-ea02c604123e} tm [t_lookup.c:439]: matching_3261(): RFC3261 transaction matched, tid=Sg9eBr2tSDU5c Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: {1 28924918 CANCEL 39d19e18-afa6-1239-1dba-ea02c604123e} tm [t_lookup.c:823]: t_lookupOriginalT(): canceled transaction found (0x7f742bb6d000)! Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: {1 28924918 CANCEL 39d19e18-afa6-1239-1dba-ea02c604123e} tm [t_lookup.c:826]: t_lookupOriginalT(): found - lookup completed Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: {1 28924918 CANCEL 39d19e18-afa6-1239-1dba-ea02c604123e} tm [t_msgbuilder.c:412]: build_local_reparse(): duplicate From header Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: ERROR: {1 28924918 CANCEL 39d19e18-afa6-1239-1dba-ea02c604123e} tm [t_msgbuilder.c:531]: build_local_reparse(): cannot build CANCEL request Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: ERROR: {1 28924918 CANCEL 39d19e18-afa6-1239-1dba-ea02c604123e} tm [t_cancel.c:297]: cancel_branch(): attempt to build a CANCEL failed Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: ERROR: {1 28924918 CANCEL 39d19e18-afa6-1239-1dba-ea02c604123e} tm [t_fwd.c:1434]: e2e_cancel(): cancel error Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: {1 28924918 CANCEL 39d19e18-afa6-1239-1dba-ea02c604123e} tm [t_reply.c:1761]: cleanup_uac_timers(): RETR/FR timers reset Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: {1 28924918 CANCEL 39d19e18-afa6-1239-1dba-ea02c604123e} tm [t_reply.c:633]: _reply_light(): reply sent out - buf=0x7f74317ec440: SIP/2.0 500 cancel e... shmem=0x7f742bb77260: SIP/2.0 500 cancel e Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: {1 28924918 CANCEL 39d19e18-afa6-1239-1dba-ea02c604123e} tm [t_reply.c:644]: _reply_light(): finished Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: {1 28924918 CANCEL 39d19e18-afa6-1239-1dba-ea02c604123e} tm [t_funcs.c:376]: t_relay_to(): new transaction forwarded Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: {1 28924918 CANCEL 39d19e18-afa6-1239-1dba-ea02c604123e} <core> [core/receive.c:437]: receive_msg(): request-route executed in: 1125 usec Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: {1 28924918 CANCEL 39d19e18-afa6-1239-1dba-ea02c604123e} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: message repeated 5 times: [ DEBUG: {1 28924918 CANCEL 39d19e18-afa6-1239-1dba-ea02c604123e} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)] Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: {1 28924918 CANCEL 39d19e18-afa6-1239-1dba-ea02c604123e} <core> [core/xavp.c:539]: xavp_destroy_list(): destroying xavp list (nil) Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: message repeated 2 times: [ DEBUG: {1 28924918 CANCEL 39d19e18-afa6-1239-1dba-ea02c604123e} <core> [core/xavp.c:539]: xavp_destroy_list(): destroying xavp list (nil)] Dec 3 01:03:43 kam3-lax /usr/sbin/kamailio[2451]: DEBUG: {1 28924918 CANCEL 39d19e18-afa6-1239-1dba-ea02c604123e} <core> [core/receive.c:528]: receive_msg(): cleaning up ```
#### SIP Traffic
<!-- If the issue is exposed by processing specific SIP messages, grab them with ngrep or save in a pcap file, then add them next, or attach to issue, or provide a link to download them (e.g., to a pastebin site). -->
``` CANCEL sip:john.webrtc@bf96cc.domain.com SIP/2.0 v:SIP/2.0/UDP a.b.c.d:5081;rport;branch=z9hG4bKgZ5FU4aUKXjXm Route:sip:kam3.rtp.lax.domain.net:5060 Max-Forwards:68 f:"user 1002"sip:+1002@bf96cc.domain.com;tag=8FUg427jU6pva t:sip:john.webrtc@bf96cc.domain.com i:98fa8010-afa4-1239-1dba-ea02c604123e CSeq:28924569 CANCEL Reason:SIP;cause=487;text="ORIGINATOR_CANCEL" l:0 ```
### Possible Solutions
<!-- If you found a solution or workaround for the issue, describe it. Ideally, provide a pull request with a fix. -->
I found that Kamailio versions 5.2.10 and 5.2.8 do not have this issue, so for now have downgraded to 5.2.8.
### Additional Information
* **Kamailio Version** - output of `kamailio -v`
``` version: kamailio 5.4.2 (x86_64/linux) flags: USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MMAP, PKG_MALLOC, Q_MALLOC, F_MALLOC, TLSF_MALLOC, DBG_SR_MEMORY, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES ADAPTIVE_WAIT_LOOPS 1024, MAX_RECV_BUFFER_SIZE 262144, MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. id: unknown compiled with gcc 5.4.0 ```
* **Operating System**: Ubuntu 16.04.7 LTS
<!-- Details about the operating system, the type: Linux (e.g.,: Debian 8.4, Ubuntu 16.04, CentOS 7.1, ...), MacOS, xBSD, Solaris, ...; Kernel details (output of `uname -a`) -->
``` Linux kam3-lax 4.4.0-194-generic #226-Ubuntu SMP Wed Oct 21 10:19:36 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux ```