#664 Problem on B2B_LOGIC - lumps_len called with null send_sock

1.9.x
closed-fixed
None
5
2014-08-15
2013-06-04
Daniel Zanutti
No

Hi

I have 2 opensips instances running on same machine. First instance (port 5060) does all billing and authentication stuff and forward to second, the second instance (port 5080) just enable B2B with default "top hiding" scenario and send the call to destination.

The problem is, on second machine, when B2B is called, i'm getting some CRITICAL errors on log:

Jun 4 17:22:58 /sbin/opensips[2740]: CRITICAL:core:lumps_len: lumps_len called with null send_sock
Jun 4 17:22:58 /sbin/opensips[2740]: CRITICAL:core:lump_check_opt: null send socket
Jun 4 17:22:58 /sbin/opensips[2740]: CRITICAL:core:lump_check_opt: null send socket
Jun 4 17:22:58 /sbin/opensips[2740]: CRITICAL:core:lump_check_opt: null send socket
Jun 4 17:22:58 /sbin/opensips[2740]: CRITICAL:core:lump_check_opt: null send socket
Jun 4 17:22:58 /sbin/opensips[2740]: CRITICAL:core:process_lumps: null bind_address
Jun 4 17:22:58 /sbin/opensips[2740]: CRITICAL:core:lump_check_opt: null send socket
Jun 4 17:22:58 /sbin/opensips[2740]: CRITICAL:core:lump_check_opt: null send socket
Jun 4 17:22:58 /sbin/opensips[2740]: CRITICAL:core:lump_check_opt: null send socket
Jun 4 17:22:58 /sbin/opensips[2740]: CRITICAL:core:lump_check_opt: null send socket

And unexpected behavior after that... The call is sucessfuly completed but 200 OK sent FROM instance 2, back to instance 1 has weird Record-Route information:

SIP/2.0 200 OK.
Record-Route: <sip:;r2=on;lr;ftag=3822e126>.
Record-Route: <sip:200.200.200.200:5080;r2=on;lr;ftag=3822e126>.
Record-Route: <sip:200.200.200.200;lr;ftag=3822e126;did=337.0ad9b947>.
Via: SIP/2.0/UDP 200.200.200.200:5060;branch=z9hG4bK7679.c3df2a92.0.
Via: SIP/2.0/UDP 10.0.102.18:2414;received=187.38.72.114;branch=z9hG4bK-d8754z-56cfa8370854eb59-1---d8754z-;rport=2414.
To: sip:01122223333@s05.test.com;tag=B2B.464.299.
From: sip:1000@s05.test.com;tag=3822e126.
Call-ID: YThmYjViNDgxNTk4ZjBjNTM5YTUxMDQ1OWI1OGU2ZDA.
CSeq: 2 INVITE.
Content-Type: application/sdp.
Supported: timer, precondition, path, replaces.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY.
Contact: <sip:200.200.200.200:5080>.
Server: OpenSIPS (1.9.1-notls (x86_64/linux)).
Content-Length: 251.

When Caller confirm 200 OK with ACK, the ACK is never forward to destination so Callee keep sending 200 OK.

On BYE, Opensips report some errors due to above problem:
Jun 4 17:23:04 /sbin/opensips[2742]: CRITICAL:core:mk_proxy: could not resolve hostname: ";r2=on"
Jun 4 17:23:04 /sbin/opensips[2742]: ERROR:tm:uri2proxy: bad host name in URI <sip:;r2=on;lr;ftag=07ebbe1f>
Jun 4 17:23:04 /sbin/opensips[2742]: ERROR:tm:t_forward_nonack: failure to add branches

Could someone take a look?
Thanks

Discussion

    • assigned_to: Bogdan-Andrei Iancu
     
  • Hi Daniel,

    What message is it under processing when you get the critical logs ? at INVITE req ? reply ?

    Regards,
    Bogdan

     
  • Daniel Zanutti
    Daniel Zanutti
    2013-06-11

    Hi Bogdan

    Sorry for delay.

    It was on INVITE. Tested changing destination to invalid IP to force not receiving any response and same critical logs appeared:

    Jun 11 02:22:34 s05 /sbin/opensips[8926]: CRITICAL:core:lumps_len: lumps_len called with null send_sock
    Jun 11 02:22:34 s05 /sbin/opensips[8926]: CRITICAL:core:lump_check_opt: null send socket
    Jun 11 02:22:34 s05 /sbin/opensips[8926]: CRITICAL:core:lump_check_opt: null send socket
    Jun 11 02:22:34 s05 /sbin/opensips[8926]: CRITICAL:core:lump_check_opt: null send socket
    Jun 11 02:22:34 s05 /sbin/opensips[8926]: CRITICAL:core:lump_check_opt: null send socket
    Jun 11 02:22:34 s05 /sbin/opensips[8926]: CRITICAL:core:process_lumps: null bind_address
    Jun 11 02:22:34 s05 /sbin/opensips[8926]: CRITICAL:core:lump_check_opt: null send socket
    Jun 11 02:22:34 s05 /sbin/opensips[8926]: CRITICAL:core:lump_check_opt: null send socket
    Jun 11 02:22:34 s05 /sbin/opensips[8926]: CRITICAL:core:lump_check_opt: null send socket
    Jun 11 02:22:34 s05 /sbin/opensips[8926]: CRITICAL:core:lump_check_opt: null send socket
    Jun 11 02:22:34 s05 /sbin/opensips[8926]: INFO:b2b_logic:b2bl_add_client: adding entity [0x7f52b56c31d0]->[B2B.405.885580] to tuple [0x7f52b56c6108]->[917.0]

     
  • Daniel Zanutti
    Daniel Zanutti
    2013-06-11

    Just saw that Record-Route posted is empty. It had some data... Got another log, posting:
    Record-Route: sip:;r2=on;lr;ftag=18c66a7c
    Record-Route: sip:200.200.200.200:5080;r2=on;lr;ftag=18c66a7c
    Record-Route: sip:200.200.200.200;lr;ftag=18c66a7c;did=b59.9aa05172

     
    Last edit: Daniel Zanutti 2013-06-11
  • Daniel Zanutti
    Daniel Zanutti
    2013-06-26

    Hi Bogdan

    Could you take a look on what's hapenning?

     
  • B Buitenhuis
    B Buitenhuis
    2013-07-04

    Hi,

    We have the same problem when using b2b hiding. We are using the load balancer module in combination with b2b.

    In de log file
    Jul 4 12:21:29 sbc10 opensips: CRITICAL:core:lumps_len: lumps_len called with null send_sock
    Jul 4 12:21:29 sbc10 opensips: CRITICAL:core:lump_check_opt: null send socket
    Jul 4 12:21:29 sbc10 opensips: CRITICAL:core:lump_check_opt: null send socket
    Jul 4 12:21:29 sbc10 opensips: CRITICAL:core:lump_check_opt: null send socket
    Jul 4 12:21:29 sbc10 opensips: CRITICAL:core:lump_check_opt: null send socket
    Jul 4 12:21:29 sbc10 opensips: CRITICAL:core:process_lumps: null bind_address
    Jul 4 12:21:29 sbc10 opensips: CRITICAL:core:lump_check_opt: null send socket
    Jul 4 12:21:29 sbc10 opensips: CRITICAL:core:lump_check_opt: null send socket
    Jul 4 12:21:29 sbc10 opensips: CRITICAL:core:lump_check_opt: null send socket
    Jul 4 12:21:29 sbc10 opensips: CRITICAL:core:lump_check_opt: null send socket

    Ander after some time:
    Jul 4 12:22:34 sbc10 opensips: CRITICAL:core:mk_proxy: could not resolve hostname: ";r2=on"
    Jul 4 12:22:34 sbc10 opensips: ERROR:tm:uri2proxy: bad host name in URI <sip:;r2=on;lr;ftag=as6cbedac2;did=fb.45bc406>
    Jul 4 12:22:34 sbc10 opensips: ERROR:tm:uri2su: failed create a dst proxy
    Jul 4 12:22:34 sbc10 opensips: ERROR:tm:t_uac: no socket found
    Jul 4 12:22:34 sbc10 opensips: ERROR:b2b_entities:b2b_send_indlg_req: failed to send request [BYE] for dlg=[0x7f25301bf3e0] uac_tran=[(nil)]
    Jul 4 12:22:34 sbc10 opensips: ERROR:b2b_entities:b2b_send_request: Failed to send request
    Jul 4 12:22:34 sbc10 opensips: ERROR:b2b_logic:b2b_logic_notify_request: Sending request failed [B2B.147.462]
    Jul 4 12:22:55 sbc10 opensips: INFO:b2b_logic:b2bl_clean: Found expired tuple [514.0]: delete and send BYEs
    Jul 4 12:23:32 sbc10 opensips: CRITICAL:core:mk_proxy: could not resolve hostname: ";r2=on"
    Jul 4 12:23:32 sbc10 opensips: ERROR:tm:uri2proxy: bad host name in URI <sip:;r2=on;lr;ftag=as6cbedac2;did=fb.45bc406>
    Jul 4 12:23:32 sbc10 opensips: ERROR:tm:t_forward_nonack: failure to add branches

     
  • Phat Wu
    Phat Wu
    2013-10-18

    Hi, I got the same problem. I implemented B2BUA REFER, when a UA send INVITE message, it will be dropped on OpenSIPs server and UA will receive "No response" message.

    This is my OpenSIPs log:
    Oct 18 08:22:25 opensips /usr/local/opensips/sbin/opensips[58571]: avant b2b_init_request
    Oct 18 08:22:25 opensips /usr/local/opensips/sbin/opensips[58571]: CRITICAL:core:lumps_len: lumps_len called with null send_sock
    Oct 18 08:22:25 opensips /usr/local/opensips/sbin/opensips[58571]: CRITICAL:core:lump_check_opt: null send socket
    Oct 18 08:22:25 opensips /usr/local/opensips/sbin/opensips[58571]: CRITICAL:core:lump_check_opt: null send socket
    Oct 18 08:22:25 opensips /usr/local/opensips/sbin/opensips[58571]: CRITICAL:core:lump_check_opt: null send socket
    Oct 18 08:22:25 opensips /usr/local/opensips/sbin/opensips[58571]: CRITICAL:core:lump_check_opt: null send socket
    Oct 18 08:22:25 opensips /usr/local/opensips/sbin/opensips[58571]: CRITICAL:core:process_lumps: null bind_address
    Oct 18 08:22:25 opensips /usr/local/opensips/sbin/opensips[58571]: CRITICAL:core:lump_check_opt: null send socket
    Oct 18 08:22:25 opensips /usr/local/opensips/sbin/opensips[58571]: CRITICAL:core:lump_check_opt: null send socket
    Oct 18 08:22:25 opensips /usr/local/opensips/sbin/opensips[58571]: CRITICAL:core:lump_check_opt: null send socket
    Oct 18 08:22:25 opensips /usr/local/opensips/sbin/opensips[58571]: CRITICAL:core:lump_check_opt: null send socket
    Oct 18 08:22:25 opensips /usr/local/opensips/sbin/opensips[58571]: INFO:b2b_logic:b2bl_add_client: adding entity [0x7f2f1060b5d8]->[B2B.72.4909449] to tuple [0x7f2f10605d90]->[72.0]
    Oct 18 08:22:25 opensips /usr/local/opensips/sbin/opensips[58571]: apres b2b_init_request
    Oct 18 08:22:25 opensips /usr/local/opensips/sbin/opensips[58568]: b2b_reply (B2B.72.4909449)
    Oct 18 08:22:25 opensips /usr/local/opensips/sbin/opensips[58571]: b2b_request (22663)
    Oct 18 08:22:25 opensips /usr/local/opensips/sbin/opensips[58571]: avant b2b_init_request
    Oct 18 08:22:25 opensips /usr/local/opensips/sbin/opensips[58571]: CRITICAL:core:lumps_len: lumps_len called with null send_sock
    Oct 18 08:22:25 opensips /usr/local/opensips/sbin/opensips[58571]: CRITICAL:core:lump_check_opt: null send socket
    Oct 18 08:22:25 opensips /usr/local/opensips/sbin/opensips[58571]: CRITICAL:core:lump_check_opt: null send socket
    Oct 18 08:22:25 opensips /usr/local/opensips/sbin/opensips[58571]: CRITICAL:core:lump_check_opt: null send socket
    Oct 18 08:22:25 opensips /usr/local/opensips/sbin/opensips[58571]: CRITICAL:core:lump_check_opt: null send socket
    Oct 18 08:22:25 opensips /usr/local/opensips/sbin/opensips[58571]: CRITICAL:core:process_lumps: null bind_address
    Oct 18 08:22:25 opensips /usr/local/opensips/sbin/opensips[58571]: CRITICAL:core:lump_check_opt: null send socket
    Oct 18 08:22:25 opensips /usr/local/opensips/sbin/opensips[58571]: CRITICAL:core:lump_check_opt: null send socket
    Oct 18 08:22:25 opensips /usr/local/opensips/sbin/opensips[58571]: CRITICAL:core:lump_check_opt: null send socket
    Oct 18 08:22:25 opensips /usr/local/opensips/sbin/opensips[58571]: CRITICAL:core:lump_check_opt: null send socket
    Oct 18 08:22:25 opensips /usr/local/opensips/sbin/opensips[58565]: b2b_reply (B2B.72.5003053)
    Oct 18 08:22:25 opensips /usr/local/opensips/sbin/opensips[58571]: INFO:b2b_logic:b2bl_add_client: adding entity [0x7f2f1060b5d8]->[B2B.72.5003053] to tuple [0x7f2f10605d90]->[72.0]
    Oct 18 08:22:25 opensips /usr/local/opensips/sbin/opensips[58571]: apres b2b_init_request
    Oct 18 08:22:25 opensips /usr/local/opensips/sbin/opensips[58571]: b2b_request (22663)

    P/S: avant b2b_init_request & apres b2b_init_request are marks where start & stop b2b_init_request("refer")

    I attached my OpenSIPs config file, OpenSIPs log file, refer script.
    Can anyboy help me?

     
  • A fix was uploaded on all branches starting with 1.9 . Please give it a try and see if works for you.

    Regards,
    Bogdan

     
    • status: open --> open-fixed
     
    • status: open-fixed --> closed-fixed