Hej
I was wondering if SRX DHCP Server can distribute IP addresses that are not in it own subnet?. So far I have been only succesful when the address-pool is in the same subnet as the SRX interface like in below. If I do change the subnet values it does not work
show interfaces ge-0/0/1
description to-EX3400;
vlan-tagging;
unit 0 {
vlan-id 202;
family inet {
address 66.66.202.2/24;
}
}
show routing-instances OSCAR-66-1-EX3400
interface ge-0/0/1.0;
instance-type virtual-router;
system {
services {
dhcp-local-server {
group DHCP {
interface ge-0/0/1.0;
}
}
}
}
access {
address-assignment {
pool DHCP-66 {
family inet {
network 66.66.202.0/24;
range TEST {
low 66.66.202.100;
high 66.66.202.110;
}
dhcp-attributes {
router {
66.66.202.1;
From the traceoptions I see the below when I try a different subnet. There are few repeating errors for Option 82 etc.
Jul 30 08:07:16.977581 [MSTR][NOTE] jdhcpd_io_reader: Recv DHCP packet on logical-system default, routing-instance OSCAR-66-1-EX3400, if ge-0/0/1.0 size 265
Jul 30 08:07:16.977656 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ DHCP/BOOTP from == 0.0.0.0, port == 68 ]--
Jul 30 08:07:16.977766 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ DHCP/BOOTP size == 265, op == 1 ]--
Jul 30 08:07:16.977809 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ DHCP/BOOTP flags == 8000 ]--
Jul 30 08:07:16.977842 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ DHCP/BOOTP htype == 1, hlen == 6 ]--
Jul 30 08:07:16.977874 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ DHCP/BOOTP hops == 0, xid == 6332e044 ]--
Jul 30 08:07:16.977906 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ DHCP/BOOTP secs == 0, flags == 8000 ]--
Jul 30 08:07:16.977940 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ DHCP/BOOTP ciaddr == 0.0.0.0 ]--
Jul 30 08:07:16.977973 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ DHCP/BOOTP yiaddr == 0.0.0.0 ]--
Jul 30 08:07:16.978006 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ DHCP/BOOTP siaddr == 0.0.0.0 ]--
Jul 30 08:07:16.978039 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ DHCP/BOOTP giaddr == 0.0.0.0 ]--
Jul 30 08:07:16.978090 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ DHCP/BOOTP chaddr == 9c cc 83 a0 8b 70 00 00 00 00 00 00 00 00 00 00 ]--
Jul 30 08:07:16.978123 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ DHCP/BOOTP sname == ]--
Jul 30 08:07:16.978154 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ DHCP/BOOTP file == ]--
Jul 30 08:07:16.978193 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ OPTION code 53, len 1, data DHCP-DISCOVER ]--
Jul 30 08:07:16.978244 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ OPTION code 12, len 12, data 4e 56 30 32 31 36 34 35 30 31 33 33 ]--
Jul 30 08:07:16.979161 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ OPTION code 51, len 4, data 00 01 51 80 ]--
Jul 30 08:07:16.979235 [MSTR][INFO] [default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ OPTION code 255, len 0 ]--
Jul 30 08:07:16.979516 [MSTR][DEBUG] client_key_compose: Composing key (0x2bb4600) for cid_l 0, cid NULL, mac 9c cc 83 a0 8b 70, htype 1, subnet 66.66.202.2, ifindx 0, opt82_l 0, opt82 NULL
Jul 30 08:07:16.979589 [MSTR][DEBUG] client_key_compose: Successfully composed CK_TYPE_HW_ADDR_ON_SUBNET (2) client key object.
Jul 30 08:07:16.979632 [MSTR][DEBUG] client_key_print: key_type CK_TYPE_HW_ADDR_ON_SUBNET (2): subnet 66.66.202.2, MAC htype 1, Addr 9c cc 83 a0 8b 70
Jul 30 08:07:16.979666 [MSTR][DEBUG] client_key_print: key_type CK_TYPE_HW_ADDR_ON_SUBNET (2) other fields: subnet 66.66.202.2, ifindex 0, opt82_len 0, -
Jul 30 08:07:16.979706 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] jdhcpd_find_client_from_client_pdu: BOOTPREQUEST could not find client table ent
Jul 30 08:07:16.979743 [MSTR][DEBUG] jdhcpd_packet_map_to_wholesale_client: No wholesale clients moved out routing instance default:OSCAR-66-1-EX3400
Jul 30 08:07:16.979775 [MSTR][DEBUG] jdhcpd_packet_map_to_wholesale_client: Client entry NOT found
Jul 30 08:07:16.979804 [MSTR][NOTE] jdhcpd_packet_handle: RECEIVE DISCOVER: stats_safd 0x0 , safd 0x2b0c800 ge-0/0/1.0
Jul 30 08:07:16.979853 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] jdhcpd_process_forward_only_or_drop: Returning ... forward-only flags not set (flags=deaddead, rc_flags 8a40809) for routing context 6
Jul 30 08:07:16.979900 [MSTR][DEBUG] jdhcpd_short_cycle_protection_config_get: Short cycle protection NOT configured for ge-0/0/1.0
Jul 30 08:07:16.979947 [MSTR][INFO] cedb_entry_new_common: New client (0x2579800), family=INET, index=65548, state=0
Jul 30 08:07:16.979983 [MSTR][DEBUG] cedb_entry_new_common: DHCPv4 client entry ADDED, app_type 1 routing context default:OSCAR-66-1-EX3400
Jul 30 08:07:16.980041 [MSTR][DEBUG] jdhcpd_name_2_const: ifl ge-0/0/1.0 fpc 0 pic 0 port 1 chnl 4294967295 chnl_max 4294967295 unit 0
Jul 30 08:07:16.980103 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][SID=0] _jdhcpd_stale_timer_add: Added stale-timer for client:0x2579800
Jul 30 08:07:16.980170 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][SID=0] jdhcpd_packet_handle: new client table entry created for ifindex 81
Jul 30 08:07:16.980217 [MSTR][DEBUG] jdhcpd_name_2_const: ifl ge-0/0/1.0 fpc 0 pic 0 port 1 chnl 4294967295 chnl_max 4294967295 unit 0
Jul 30 08:07:16.980259 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] jdhcpd_process_offer_advertise_delay: Returning ... offer delay not set (flags=0, rc_flags 8a40809) for routing context 6, rc(257a000)
Jul 30 08:07:16.980303 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][SID=0] jdhcpd_packet_handle: Set client next-hop mac addr: 00 00 00 00 00 00 state(0)
Jul 30 08:07:16.980412 [MSTR][INFO] [default:OSCAR-66-1-EX3400][SVR][INET][SID=0] JDHCPD_CLIENT_EVENT: Client(0x2579800) got event CLIENT_EVENT_DISCOVER_PDU in state LOCAL_SERVER_STATE_INIT flags 1: 0x0 2: 0x0 3: 0x0 nm: 0x0
And this is when DHCP assigns an address succesfully if I set the addresspool to be same subnet as in SRX interface
Jul 30 08:15:48.540074 [MSTR][NOTE] jdhcpd_io_reader: Recv DHCP packet on logical-system default, routing-instance OSCAR-66-1-EX3400, if ge-0/0/1.0 size 293
Jul 30 08:15:48.540160 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ DHCP/BOOTP from == 0.0.0.0, port == 68 ]--
Jul 30 08:15:48.540205 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ DHCP/BOOTP size == 293, op == 1 ]--
Jul 30 08:15:48.540238 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ DHCP/BOOTP flags == 8000 ]--
Jul 30 08:15:48.540270 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ DHCP/BOOTP htype == 1, hlen == 6 ]--
Jul 30 08:15:48.540338 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ DHCP/BOOTP hops == 0, xid == 5e84cadb ]--
Jul 30 08:15:48.540374 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ DHCP/BOOTP secs == 0, flags == 8000 ]--
Jul 30 08:15:48.540408 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ DHCP/BOOTP ciaddr == 0.0.0.0 ]--
Jul 30 08:15:48.540442 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ DHCP/BOOTP yiaddr == 0.0.0.0 ]--
Jul 30 08:15:48.540475 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ DHCP/BOOTP siaddr == 0.0.0.0 ]--
Jul 30 08:15:48.540508 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ DHCP/BOOTP giaddr == 0.0.0.0 ]--
Jul 30 08:15:48.540559 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ DHCP/BOOTP chaddr == 9c cc 83 a0 8b 70 00 00 00 00 00 00 00 00 00 00 ]--
Jul 30 08:15:48.540592 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ DHCP/BOOTP sname == ]--
Jul 30 08:15:48.540623 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ DHCP/BOOTP file == ]--
Jul 30 08:15:48.540668 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ OPTION code 54, len 4, data 42 42 ca 02 ]--
Jul 30 08:15:48.540721 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ OPTION code 55, len 14, data 03 33 01 0f 06 42 43 78 2c 2b 96 0c 07 2a ]--
Jul 30 08:15:48.540759 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ OPTION code 50, len 4, data 42 42 ca 64 ]--
Jul 30 08:15:48.540793 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ OPTION code 53, len 1, data DHCP-REQUEST ]--
Jul 30 08:15:48.540839 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ OPTION code 12, len 12, data 4e 56 30 32 31 36 34 35 30 31 33 33 ]--
Jul 30 08:15:48.540877 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ OPTION code 51, len 4, data 00 01 51 80 ]--
Jul 30 08:15:48.540931 [MSTR][INFO] [default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] --[ OPTION code 255, len 0 ]--
Jul 30 08:15:48.540993 [MSTR][DEBUG] client_key_compose: Composing key (0x2bb4600) for cid_l 0, cid NULL, mac 9c cc 83 a0 8b 70, htype 1, subnet 66.66.202.2, ifindx 0, opt82_l 0, opt82 NULL
Jul 30 08:15:48.541034 [MSTR][DEBUG] client_key_compose: Successfully composed CK_TYPE_HW_ADDR_ON_SUBNET (2) client key object.
Jul 30 08:15:48.541073 [MSTR][DEBUG] client_key_print: key_type CK_TYPE_HW_ADDR_ON_SUBNET (2): subnet 66.66.202.2, MAC htype 1, Addr 9c cc 83 a0 8b 70
Jul 30 08:15:48.541106 [MSTR][DEBUG] client_key_print: key_type CK_TYPE_HW_ADDR_ON_SUBNET (2) other fields: subnet 66.66.202.2, ifindex 0, opt82_len 0, -
Jul 30 08:15:48.541148 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_configuration_match: sus_ifl:0x2ba5000 (ge-0/0/1.0)
Jul 30 08:15:48.542256 [MSTR][NOTE] [default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_packet_handle: RECEIVE REQUEST: stats_safd 0x2b0c800 ge-0/0/1.0, incoming_safd 0x2b0c800 ge-0/0/1.0, demux 0x0 , safd 0x2b0c800 ge-0/0/1.0
Jul 30 08:15:48.542348 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_packet_handle: saved server address as 66.66.202.2
Jul 30 08:15:48.542392 [MSTR][INFO] [default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] JDHCPD_CLIENT_EVENT: Client(0x2579800) got event CLIENT_EVENT_REQUEST_PDU in state LOCAL_SERVER_STATE_CLIENT_SELECTING flags 1: 0x20000 2: 0x80 3: 0x0 nm: 0x0
Jul 30 08:15:48.542436 [MSTR][DEBUG] jdhcpd_pool_find: cfg 257b000, pool_name 2546530, DHCP-66
Jul 30 08:15:48.542467 [MSTR][DEBUG] jdhcpd_pool_find: Pool DHCP-66 found 0x2b0e800 w/ cfg container 0x257b000
Jul 30 08:15:48.542499 [MSTR][DEBUG] rc_entry_sus_find_ipaddr: rc_entry_sus_find_ipaddr: TYPE 1 for IP ADDR 66.66.202.2 in routing context LR default/RI OSCAR-66-1-EX3400
Jul 30 08:15:48.542533 [MSTR][DEBUG] rc_entry_sus_find_ipaddr: Entry w/ ref_count 1 found when searching 'subunit by ip-addr' for IP ADDR 66.66.202.2 in routing context LR default/RI OSCAR-66-1-EX3400
Jul 30 08:15:48.542605 [MSTR][INFO] jdhcpd_auth_profile_activate: auth activate req for session 17: flags1:0x20000; flags2:0x80
Jul 30 08:15:48.542637 Before adding to teardown list, jdhcpd_inst.authd_restart_teardown_count 0
Jul 30 08:15:48.542660 LIST IS EMPTY, jdhcpd_inst.authd_restart_teardown_count 0
Jul 30 08:15:48.542684 Added client w/ session_id 17 in state LOCAL_SERVER_STATE_CLIENT_SELECTING, to authd_restart_teardown list, count authd_restart_teardown_count 1
Jul 30 08:15:48.542734 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_set_fsm_state: FSM state change : LOCAL_SERVER_STATE_CLIENT_SELECTING --> LOCAL_SERVER_STATE_WAIT_AUTH_ACT_PROF
Jul 30 08:15:48.542769 [MSTR][INFO] jdhcpd_client_set_pkt: *********** Setting v4 packet 0x2bb4400
Jul 30 08:15:48.625944 jdhcpd_jauthd_resp_cb: session-id:17 req-id:65552 activate-ipv4 success none
Jul 30 08:15:48.626048 [MSTR][INFO] jdhcpd_service_activated_rply_proc: Got service-activated reply rqst_id = 65552 (session Id 17)
Jul 30 08:15:48.626086 [MSTR][INFO] jdhcpd_authd_restart_teardown_delete: Request to remove client w. session_id 17 in state 14 from authd_restart_teardown list, count authd_restart_teardown_count 1
Jul 30 08:15:48.626124 Removed LAST client from authd_restart teardown list, zero out COUNT authd_restart_teardown_count
Jul 30 08:15:48.626165 [MSTR][INFO] [default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] JDHCPD_CLIENT_EVENT: Client(0x2579800) got event CLIENT_EVENT_AUTH_SVC_ACK in state LOCAL_SERVER_STATE_WAIT_AUTH_ACT_PROF flags 1: 0x20000 2: 0x80 3: 0x0 nm: 0x0
Jul 30 08:15:48.626208 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_set_fsm_state: FSM state change : LOCAL_SERVER_STATE_WAIT_AUTH_ACT_PROF --> LOCAL_SERVER_STATE_WAIT_CM_ADD
Jul 30 08:15:48.626253 [MSTR][INFO] blq_tree_entry_add: BLQ-AVL - A new entry/node is added, new count of entries/nodes in blq tree 1
Jul 30 08:15:48.626369 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_add_client_in_blq_tree_all_entries: BLQ-AVL - Client is added in general blq AVL tree's list, number of clients in this list 1
Jul 30 08:15:48.626428 [MSTR][INFO] [default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_persistent_is_entry_in_file_allowed: client_type=1, client->state=6
Jul 30 08:15:48.626475 [MSTR][INFO] [default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_fill_client_sdb_private_data: Mirroring disabled (ha_graceful_switchover false) 4242:ca64:ffff:ff00::4242:ca02
Jul 30 08:15:48.626509 [MSTR][DEBUG] jdhcpd_pool_find: cfg 257b000, pool_name 2546530, DHCP-66
Jul 30 08:15:48.626539 [MSTR][DEBUG] jdhcpd_pool_find: Pool DHCP-66 found 0x2b0e800 w/ cfg container 0x257b000
Jul 30 08:15:48.626576 [MSTR][INFO] [default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_get_v4_v6_protocol_attributes: get configured protocol-attributes
Jul 30 08:15:48.626640 [MSTR][INFO] [default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_fill_client_sdb_private_data: Allocated memory to store in SDB, total mirrored length 240, client length 240, dual stack peer client length 0, session-id 17
Jul 30 08:15:48.626694 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_write_private_data: Saved NON-DEMUX interface name ge-0/0/1.0 into mirroring ha_info
Jul 30 08:15:48.626725 [MSTR][DEBUG] jdhcpd_pool_find: cfg 257b000, pool_name 2546530, DHCP-66
Jul 30 08:15:48.626753 [MSTR][DEBUG] jdhcpd_pool_find: Pool DHCP-66 found 0x2b0e800 w/ cfg container 0x257b000
Jul 30 08:15:48.626788 [MSTR][INFO] [default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_get_v4_v6_protocol_attributes: get configured protocol-attributes
Jul 30 08:15:48.626833 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_write_private_data: ++++Added TLV for WHOLESALE LR name default length 7
Jul 30 08:15:48.627078 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_write_private_data: ++++Added TLV for WHOLESALE RI name OSCAR-66-1-EX3400 length 17
Jul 30 08:15:48.627126 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_write_private_data: Added TLV for last_packet_time length 4, last_packet_time: 1596096948
Jul 30 08:15:48.627163 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_write_private_data: Added TLV for active_lq_last_update_time length 4, active_lq_last_update_time: 1596096948
Jul 30 08:15:48.627201 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_write_private_data: ++++Added TLV for Incoming dhcp options length 23
Jul 30 08:15:48.627267 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_mirrorsdb_add_client: Successfully saved private data for 66.66.202.100 in SDB, length 240
Jul 30 08:15:48.627314 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_client_correlation_id_update: setting the client correlation_id 2 in state 6.
Jul 30 08:15:48.627422 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_mirror_add_client: SDB ACK will notify us for mirroring ADD for 66.66.202.100, client session Id 17
Jul 30 08:15:48.650278 [MSTR][DEBUG] jdhcpd_sessiondb_mirrored_ack_cb: Successful SDB Mirrored Ack: returned code SDB_SUCCESS for session id 17 family INET, Ack WAITING
Jul 30 08:15:48.650328 [MSTR][INFO] [default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] JDHCPD_CLIENT_EVENT: Client(0x2579800) got event CLIENT_EVENT_CLIENT_SDB_MIRROR_ACK in state LOCAL_SERVER_STATE_WAIT_CM_ADD flags 1: 0x20000 2: 0x80 3: 0x0 nm: 0x0
Jul 30 08:15:48.650373 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_set_fsm_state: FSM state change : LOCAL_SERVER_STATE_WAIT_CM_ADD --> LOCAL_SERVER_STATE_WAIT_SDB_ACTIVE_MIRROR_REQ
Jul 30 08:15:48.650422 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_client_set_need_route_flag: RPD ACCESS-INTERNAL ROUTE NOT SUPPRESSED on this interface add route
Jul 30 08:15:48.650529 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_rpd_add_route_common: set rtp states to NOTINSTALL and INTERIOR so a route isn't installed in the kernel
Jul 30 08:15:48.650583 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_add_arp: Attempt to call jdhcpd_rtsock_do_arp for ACTIVE client 66.66.202.100, ifindex 81, l2 ifindex 0
Jul 30 08:15:48.650632 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] jdhcpd_rtsock_do_arp: L3ifindex (ifs) = 81, L2ifindex 0, addr_fam INET, operation 1
Jul 30 08:15:48.650689 [MSTR][DEBUG] jdhcpd_rtsock_add_media: Add media route for 66.66.202.100 on interface ge-0/0/1.0 (hw 9c:cc:83:a0:8b:70) perm
Jul 30 08:15:48.652624 [MSTR][DEBUG] jdhcpd_rtsock_add_media: SUCCESSFULL Add media route for 66.66.202.100 on interface ge-0/0/1.0 (hw 9c:cc:83:a0:8b:70) perm, l2Int
Jul 30 08:15:48.652925 [MSTR][INFO] [default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0] jdhcpd_rtsock_do_arp: ARP add for media successful for 66.66.202.100
Jul 30 08:15:48.652967 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_rpd_add_route_common: Call RPD to add route
Jul 30 08:15:48.654042 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_rpd_add_route_common: Table Id 0x1000008:Added ACTIVE ROUTE 66.66.202.2 index 81 giaddr 66.66.202.2
Jul 30 08:15:48.654131 [MSTR][INFO] [default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_subscriber_add: Updating SDB with client session state 2
Jul 30 08:15:48.654185 [MSTR][INFO] [default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_fill_client_sdb_private_data: Mirroring disabled (ha_graceful_switchover false) 4242:ca64:ffff:ff00::4242:ca02
Jul 30 08:15:48.654219 [MSTR][DEBUG] jdhcpd_pool_find: cfg 257b000, pool_name 2546530, DHCP-66
Jul 30 08:15:48.654247 [MSTR][DEBUG] jdhcpd_pool_find: Pool DHCP-66 found 0x2b0e800 w/ cfg container 0x257b000
Jul 30 08:15:48.654321 [MSTR][INFO] [default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_get_v4_v6_protocol_attributes: get configured protocol-attributes
Jul 30 08:15:48.654385 [MSTR][INFO] [default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_fill_client_sdb_private_data: Allocated memory to store in SDB, total mirrored length 240, client length 240, dual stack peer client length 0, session-id 17
Jul 30 08:15:48.654432 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_write_private_data: Saved NON-DEMUX interface name ge-0/0/1.0 into mirroring ha_info
Jul 30 08:15:48.654463 [MSTR][DEBUG] jdhcpd_pool_find: cfg 257b000, pool_name 2546530, DHCP-66
Jul 30 08:15:48.654490 [MSTR][DEBUG] jdhcpd_pool_find: Pool DHCP-66 found 0x2b0e800 w/ cfg container 0x257b000
Jul 30 08:15:48.654524 [MSTR][INFO] [default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_get_v4_v6_protocol_attributes: get configured protocol-attributes
Jul 30 08:15:48.654569 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_write_private_data: ++++Added TLV for WHOLESALE LR name default length 7
Jul 30 08:15:48.654609 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_write_private_data: ++++Added TLV for WHOLESALE RI name OSCAR-66-1-EX3400 length 17
Jul 30 08:15:48.654644 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_write_private_data: Added TLV for last_packet_time length 4, last_packet_time: 1596096948
Jul 30 08:15:48.654691 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_write_private_data: Added TLV for active_lq_last_update_time length 4, active_lq_last_update_time: 1596096948
Jul 30 08:15:48.654729 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_write_private_data: ++++Added TLV for Incoming dhcp options length 23
Jul 30 08:15:48.655388 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_client_correlation_id_update: setting the client correlation_id 3 in state 22.
Jul 30 08:15:48.655509 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_mark_and_mirror_sdb_state_active: Marked SDB state ACTIVE, client in FSM state LOCAL_SERVER_STATE_WAIT_SDB_ACTIVE_MIRROR_REQ, SDB ACK will notify us for client session Id 17
Jul 30 08:15:48.655702 [MSTR][INFO] [default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_rpd_cb_route_add: Add route success for 66.66.202.100
Jul 30 08:15:48.700292 [MSTR][DEBUG] jdhcpd_sessiondb_mirrored_ack_cb: Successful SDB Mirrored Ack: returned code SDB_SUCCESS for session id 17 family INET, Ack WAITING
Jul 30 08:15:48.700344 [MSTR][INFO] [default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] JDHCPD_CLIENT_EVENT: Client(0x2579800) got event CLIENT_EVENT_CLIENT_SDB_MIRROR_ACK in state LOCAL_SERVER_STATE_WAIT_SDB_ACTIVE_MIRROR_REQ flags 1: 0x10420050 2: 0x80 3: 0x0 nm: 0x0
Jul 30 08:15:48.700377 Received event 16 in state LOCAL_SERVER_STATE_WAIT_SDB_ACTIVE_MIRROR_REQ
Jul 30 08:15:48.700400 SDB mirroring ACK received in state 22 (LOCAL_SERVER_STATE_WAIT_SDB_ACTIVE_MIRROR_REQ), changing state to LOCAL_SERVER_STATE_WAIT_SUBSCR_ADD
Jul 30 08:15:48.700423 TESTPOINT: after SDB ACTIVE, ACK received in state LOCAL_SERVER_STATE_WAIT_SDB_ACTIVE_MIRROR_REQ
Jul 30 08:15:48.700457 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_set_fsm_state: FSM state change : LOCAL_SERVER_STATE_WAIT_SDB_ACTIVE_MIRROR_REQ --> LOCAL_SERVER_STATE_WAIT_SUBSCR_ADD
Jul 30 08:15:48.700495 [MSTR][INFO] [default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] JDHCPD_CLIENT_EVENT: Client(0x2579800) got event CLIENT_EVENT_SUBSCRIBER_ACK in state LOCAL_SERVER_STATE_WAIT_SUBSCR_ADD flags 1: 0x10420050 2: 0x80 3: 0x0 nm: 0x0
Jul 30 08:15:48.700526 Received event CLIENT_EVENT_SUBSCRIBER_ACK in state LOCAL_SERVER_STATE_WAIT_SUBSCR_ADD
Jul 30 08:15:48.701338 Found subunit stack in state LOCAL_SERVER_STATE_WAIT_SUBSCR_ADD
Jul 30 08:15:48.701426 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] safd_num_clients_bound_inc: Decremented global in-flight logins count is 0, session id 17
Jul 30 08:15:48.701485 [MSTR][DEBUG] jdhcpd_rc_lease_timer_start: starting lease timer for 86400 seconds
Jul 30 08:15:48.701587 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_client_lease_timer_start: CLIENT starting lease timer for index 65552, lease_end 1596183348
Jul 30 08:15:48.701637 Set state to LOCAL_SERVER_STATE_BOUND
Jul 30 08:15:48.701672 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_set_fsm_state: FSM state change : LOCAL_SERVER_STATE_WAIT_SUBSCR_ADD --> LOCAL_SERVER_STATE_BOUND
Jul 30 08:15:48.701802 [MSTR][INFO] [default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_add_client_in_blq_tree_all_entries: BLQ-AVL - Client is already on the blq AVL tree's list ALL.
Jul 30 08:15:48.701867 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_add_client_in_blq_tree_all_entries: BLQ-AVL - Client is added in general blq AVL tree's list, number of clients in this list 1
Jul 30 08:15:48.702163 [MSTR][WARN] jdhcpd_offer_delay_client_fsm_retry_queue_process: offer-delay: retry operation is aleady in progress/ no entries to process
Jul 30 08:15:48.702206 [MSTR][INFO] jdhcpd_client_unset_pkt: *********** Unsetting v4 packet 0x2bb4400
Jul 30 08:15:48.702240 [MSTR][DEBUG] jdhcpd_pool_find: cfg 257b000, pool_name 2546530, DHCP-66
Jul 30 08:15:48.702269 [MSTR][DEBUG] jdhcpd_pool_find: Pool DHCP-66 found 0x2b0e800 w/ cfg container 0x257b000
Jul 30 08:15:48.702314 [MSTR][DEBUG][default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_local_server_pdu_send: TRYING to send packet
Jul 30 08:15:48.702358 [MSTR][INFO] [default:OSCAR-66-1-EX3400][SVR][INET][ge-0/0/1.0][SID=17] jdhcpd_fill_in_server_identifier: Adding server identifier option
Jul 30 08:15:48.702388 [MSTR][DEBUG] jdhcpd_pool_find: cfg 257b000, pool_name 2546530, DHCP-66
Jul 30 08:15:48.702441 [MSTR][DEBUG] jdhcpd_pool_find: Pool DHCP-66 found 0x2b0e800 w/ cfg container 0x257b000
Jul 30 08:15:48.702475 [MSTR][DEBUG] jdhcpd_pool_find: cfg 257b000, pool_name 2546530, DHCP-66
Jul 30 08:15:48.702505 [MSTR][DEBUG] jdhcpd_pool_find: Pool DHCP-66 found 0x2b0e800 w/ cfg container 0x257b000