Dec 11 17:14:34 fw ppp[52460]: tun0: LCP: deflink: SendEchoReply(244) state = Opened Dec 11 17:14:43 fw ppp[52460]: tun0: LCP: deflink: SendEchoRequest(2822) state = Opened Dec 11 17:14:43 fw ppp[52460]: tun0: LCP: deflink: RecvEchoReply(6) state = Opened Dec 11 17:14:44 fw ppp[52460]: tun0: LCP: deflink: RecvEchoRequest(245) state = Opened Dec 11 17:14:44 fw ppp[52460]: tun0: LCP: deflink: SendEchoReply(245) state = Opened Dec 11 17:14:54 fw ppp[52460]: tun0: LCP: deflink: RecvEchoRequest(246) state = Opened Dec 11 17:14:54 fw ppp[52460]: tun0: LCP: deflink: SendEchoReply(246) state = Opened Dec 11 17:14:55 fw ppp[52460]: tun0: Command: /var/run/internet: set log all Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: deflink(ctrl): fdset(r) 0 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: deflink: fdset(r) 1 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: deflink: fdset(e) 1 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:14:55 fw ppp[52460]: tun0: Debug: deflink: DescriptorRead: read 65/2048 from 1 Dec 11 17:14:55 fw ppp[52460]: tun0: Debug: proto_LayerPull: unknown -> 0x0021 Dec 11 17:14:55 fw ppp[52460]: tun0: Debug: nat_LayerPull: PROTO_IP -> PROTO_IP Dec 11 17:14:55 fw ppp[52460]: tun0: Debug: link_PullPacket: Despatch proto 0x0021 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: deflink(ctrl): fdset(r) 0 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: deflink: fdset(r) 1 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: deflink: fdset(e) 1 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:14:55 fw ppp[52460]: tun0: Debug: deflink: DescriptorRead: read 1078/2048 from 1 Dec 11 17:14:55 fw ppp[52460]: tun0: Debug: proto_LayerPull: unknown -> 0x0021 Dec 11 17:14:55 fw ppp[52460]: tun0: Debug: nat_LayerPull: PROTO_IP -> PROTO_IP Dec 11 17:14:55 fw ppp[52460]: tun0: Debug: link_PullPacket: Despatch proto 0x0021 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: deflink(ctrl): fdset(r) 0 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: deflink: fdset(r) 1 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: deflink: fdset(e) 1 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: ---- Begin of Timer Service List--- Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: IPCP throughput timer[0x80a9be8]: freq = 1.00s, next = 0.00s, state = running Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: physical throughput timer[0x80bb068]: freq = 1.00s, next = 0.50s, state = running Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: lqm timer[0x80bddf4]: freq = 30.00s, next = 17.80s, state = running Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: hdlc timer[0x80bddb0]: freq = 60.00s, next = 47.80s, state = running Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: ---- End of Timer Service List --- Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: timer_Start: Inserting IPCP throughput timer[0x80a9be8] before lqm timer[0x80bddf4], delta = 5 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: deflink(ctrl): fdset(r) 0 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: deflink: fdset(r) 1 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: deflink: fdset(e) 1 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:14:55 fw ppp[52460]: tun0: Debug: deflink: DescriptorRead: read 55/2048 from 1 Dec 11 17:14:55 fw ppp[52460]: tun0: Debug: proto_LayerPull: unknown -> 0x0021 Dec 11 17:14:55 fw ppp[52460]: tun0: Debug: nat_LayerPull: PROTO_IP -> PROTO_IP Dec 11 17:14:55 fw ppp[52460]: tun0: Debug: link_PullPacket: Despatch proto 0x0021 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: deflink(ctrl): fdset(r) 0 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: deflink: fdset(r) 1 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: deflink: fdset(e) 1 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:14:55 fw ppp[52460]: tun0: Debug: deflink: DescriptorRead: read 49/2048 from 1 Dec 11 17:14:55 fw ppp[52460]: tun0: Debug: proto_LayerPull: unknown -> 0x0021 Dec 11 17:14:55 fw ppp[52460]: tun0: Debug: nat_LayerPull: PROTO_IP -> PROTO_IP Dec 11 17:14:55 fw ppp[52460]: tun0: Debug: link_PullPacket: Despatch proto 0x0021 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: deflink(ctrl): fdset(r) 0 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: deflink: fdset(r) 1 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: deflink: fdset(e) 1 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:55 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:14:55 fw ppp[52460]: tun0: Debug: deflink: DescriptorRead: read 1450/2048 from 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: proto_LayerPull: unknown -> 0x0021 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: nat_LayerPull: PROTO_IP -> PROTO_IP Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: link_PullPacket: Despatch proto 0x0021 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: deflink(ctrl): fdset(r) 0 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: deflink: fdset(r) 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: deflink: fdset(e) 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: Select returns 2 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: deflink: DescriptorRead: read 1450/2048 from 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: proto_LayerPull: unknown -> 0x0021 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: nat_LayerPull: PROTO_IP -> PROTO_IP Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: link_PullPacket: Despatch proto 0x0021 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: m_enqueue: len = 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: nat_LayerPush: PROTO_IP -> PROTO_IP Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: proto_LayerPush: Using 0x0021 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: link_PushPacket: Transmit proto 0x0021 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: m_enqueue: len = 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: deflink(ctrl): fdset(r) 0 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: deflink: fdset(r) 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: deflink: fdset(e) 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: deflink: fdset(w) 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: ---- Begin of Timer Service List--- Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: physical throughput timer[0x80bb068]: freq = 1.00s, next = 0.00s, state = running Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: IPCP throughput timer[0x80a9be8]: freq = 1.00s, next = 0.50s, state = running Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: lqm timer[0x80bddf4]: freq = 30.00s, next = 17.30s, state = running Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: hdlc timer[0x80bddb0]: freq = 60.00s, next = 47.30s, state = running Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: ---- End of Timer Service List --- Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: timer_Start: Inserting physical throughput timer[0x80bb068] before lqm timer[0x80bddf4], delta = 5 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: deflink(ctrl): fdset(r) 0 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: deflink: fdset(r) 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: deflink: fdset(e) 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: deflink: fdset(w) 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: Select returns 3 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: deflink: DescriptorRead: read 65/2048 from 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: proto_LayerPull: unknown -> 0x0021 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: nat_LayerPull: PROTO_IP -> PROTO_IP Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: link_PullPacket: Despatch proto 0x0021 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: m_enqueue: len = 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: link_Dequeue: Dequeued from queue 0, containing 0 more packets Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: deflink: DescriptorWrite: wrote 54(54) to 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: nat_LayerPush: PROTO_IP -> PROTO_IP Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: proto_LayerPush: Using 0x0021 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: link_PushPacket: Transmit proto 0x0021 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: m_enqueue: len = 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: deflink(ctrl): fdset(r) 0 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: deflink: fdset(r) 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: deflink: fdset(e) 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: deflink: fdset(w) 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: Select returns 3 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: deflink: DescriptorRead: read 55/2048 from 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: proto_LayerPull: unknown -> 0x0021 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: nat_LayerPull: PROTO_IP -> PROTO_IP Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: link_PullPacket: Despatch proto 0x0021 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: m_enqueue: len = 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: link_Dequeue: Dequeued from queue 0, containing 0 more packets Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: deflink: DescriptorWrite: wrote 42(42) to 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: nat_LayerPush: PROTO_IP -> PROTO_IP Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: proto_LayerPush: Using 0x0021 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: link_PushPacket: Transmit proto 0x0021 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: m_enqueue: len = 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: deflink(ctrl): fdset(r) 0 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: deflink: fdset(r) 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: deflink: fdset(e) 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: deflink: fdset(w) 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: Select returns 3 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: deflink: DescriptorRead: read 59/2048 from 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: proto_LayerPull: unknown -> 0x0021 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: nat_LayerPull: PROTO_IP -> PROTO_IP Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: link_PullPacket: Despatch proto 0x0021 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: m_enqueue: len = 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: link_Dequeue: Dequeued from queue 0, containing 0 more packets Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: deflink: DescriptorWrite: wrote 54(54) to 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: nat_LayerPush: PROTO_IP -> PROTO_IP Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: proto_LayerPush: Using 0x0021 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: link_PushPacket: Transmit proto 0x0021 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: m_enqueue: len = 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: deflink(ctrl): fdset(r) 0 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: deflink: fdset(r) 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: deflink: fdset(e) 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: deflink: fdset(w) 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: Select returns 3 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: deflink: DescriptorRead: read 55/2048 from 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: proto_LayerPull: unknown -> 0x0021 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: nat_LayerPull: PROTO_IP -> PROTO_IP Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: link_PullPacket: Despatch proto 0x0021 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: m_enqueue: len = 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: link_Dequeue: Dequeued from queue 0, containing 0 more packets Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: deflink: DescriptorWrite: wrote 54(54) to 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: nat_LayerPush: PROTO_IP -> PROTO_IP Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: proto_LayerPush: Using 0x0021 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: link_PushPacket: Transmit proto 0x0021 Dec 11 17:14:56 fw ppp[52460]: tun0: Debug: m_enqueue: len = 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: deflink(ctrl): fdset(r) 0 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: deflink: fdset(r) 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: deflink: fdset(e) 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: deflink: fdset(w) 1 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:56 fw ppp[52460]: tun0: Timer: Select returns 3 Dec 11 17:14:57 fw ppp[52460]: tun0: Debug: deflink: DescriptorRead: read 1078/2048 from 1 Dec 11 17:14:57 fw ppp[52460]: tun0: Debug: proto_LayerPull: unknown -> 0x0021 Dec 11 17:14:57 fw ppp[52460]: tun0: Debug: nat_LayerPull: PROTO_IP -> PROTO_IP Dec 11 17:14:57 fw ppp[52460]: tun0: Debug: link_PullPacket: Despatch proto 0x0021 Dec 11 17:14:57 fw ppp[52460]: tun0: Debug: m_enqueue: len = 1 Dec 11 17:14:57 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 1 Dec 11 17:14:57 fw ppp[52460]: tun0: Debug: link_Dequeue: Dequeued from queue 0, containing 0 more packets Dec 11 17:14:57 fw ppp[52460]: tun0: Debug: deflink: DescriptorWrite: wrote 71(71) to 1 Dec 11 17:14:57 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 1 Dec 11 17:14:57 fw ppp[52460]: tun0: Debug: nat_LayerPush: PROTO_IP -> PROTO_IP Dec 11 17:14:57 fw ppp[52460]: tun0: Debug: proto_LayerPush: Using 0x0021 Dec 11 17:14:57 fw ppp[52460]: tun0: Debug: link_PushPacket: Transmit proto 0x0021 Dec 11 17:14:57 fw ppp[52460]: tun0: Debug: m_enqueue: len = 1 Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: deflink(ctrl): fdset(r) 0 Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: deflink: fdset(r) 1 Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: deflink: fdset(e) 1 Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: deflink: fdset(w) 1 Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: ---- Begin of Timer Service List--- Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: IPCP throughput timer[0x80a9be8]: freq = 1.00s, next = 0.00s, state = running Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: physical throughput timer[0x80bb068]: freq = 1.00s, next = 0.50s, state = running Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: lqm timer[0x80bddf4]: freq = 30.00s, next = 16.80s, state = running Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: hdlc timer[0x80bddb0]: freq = 60.00s, next = 46.80s, state = running Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: ---- End of Timer Service List --- Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: timer_Start: Inserting IPCP throughput timer[0x80a9be8] before lqm timer[0x80bddf4], delta = 5 Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: deflink(ctrl): fdset(r) 0 Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: deflink: fdset(r) 1 Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: deflink: fdset(e) 1 Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: deflink: fdset(w) 1 Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: Select returns 3 Dec 11 17:14:57 fw ppp[52460]: tun0: Debug: deflink: DescriptorRead: read 65/2048 from 1 Dec 11 17:14:57 fw ppp[52460]: tun0: Debug: proto_LayerPull: unknown -> 0x0021 Dec 11 17:14:57 fw ppp[52460]: tun0: Debug: nat_LayerPull: PROTO_IP -> PROTO_IP Dec 11 17:14:57 fw ppp[52460]: tun0: Debug: link_PullPacket: Despatch proto 0x0021 Dec 11 17:14:57 fw ppp[52460]: tun0: Debug: m_enqueue: len = 1 Dec 11 17:14:57 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 1 Dec 11 17:14:57 fw ppp[52460]: tun0: Debug: link_Dequeue: Dequeued from queue 0, containing 0 more packets Dec 11 17:14:57 fw ppp[52460]: tun0: Debug: deflink: DescriptorWrite: wrote 1346(1346) to 1 Dec 11 17:14:57 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 1 Dec 11 17:14:57 fw ppp[52460]: tun0: Debug: nat_LayerPush: PROTO_IP -> PROTO_IP Dec 11 17:14:57 fw ppp[52460]: tun0: Debug: proto_LayerPush: Using 0x0021 Dec 11 17:14:57 fw ppp[52460]: tun0: Debug: link_PushPacket: Transmit proto 0x0021 Dec 11 17:14:57 fw ppp[52460]: tun0: Debug: m_enqueue: len = 1 Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: deflink(ctrl): fdset(r) 0 Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: deflink: fdset(r) 1 Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: deflink: fdset(e) 1 Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: deflink: fdset(w) 1 Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: Select returns 4 Dec 11 17:14:57 fw ppp[52460]: tun0: Phase: Received NGM_PPPOE_CLOSE Dec 11 17:14:57 fw ppp[52460]: tun0: Phase: deflink: Device disconnected Dec 11 17:14:57 fw ppp[52460]: tun0: CCP: deflink: State change Stopped --> Closed Dec 11 17:14:57 fw ppp[52460]: tun0: CCP: deflink: State change Closed --> Initial Dec 11 17:14:57 fw ppp[52460]: tun0: LCP: deflink: LayerDown Dec 11 17:14:57 fw ppp[52460]: tun0: LCP: deflink: State change Opened --> Starting Dec 11 17:14:57 fw ppp[52460]: tun0: Phase: deflink: open -> lcp Dec 11 17:14:57 fw ppp[52460]: tun0: ID0: 0 = ioctl(6, 2148037723, 0xbfbfe190) Dec 11 17:14:57 fw ppp[52460]: tun0: Debug: route_UpdateMTU (6) Dec 11 17:14:57 fw ppp[52460]: tun0: TCP/IP: route_UpdateMTU: Netif: 6 (tun0), dst 0.0.0.0/0, mtu 1500 Dec 11 17:14:57 fw ppp[52460]: tun0: ID0: 3 = socket(17, 3, 0) Dec 11 17:14:57 fw ppp[52460]: tun0: ID0: -1 = write(3, data, 124) Dec 11 17:14:57 fw ppp[52460]: tun0: TCP/IP: rt_Update failure: Dec 11 17:14:57 fw ppp[52460]: tun0: TCP/IP: rt_Update: Dst = 0.0.0.0/0 Dec 11 17:14:57 fw ppp[52460]: tun0: Warning: 0.0.0.0/0: Change route failed: errno: No such process Dec 11 17:14:57 fw ppp[52460]: tun0: TCP/IP: route_UpdateMTU: Netif: 6 (tun0), dst GGG.HHH.III.JJJ, mtu 1500 Dec 11 17:14:57 fw ppp[52460]: tun0: ID0: 3 = socket(17, 3, 0) Dec 11 17:14:57 fw ppp[52460]: tun0: ID0: 124 = write(3, data, 124) Dec 11 17:14:57 fw ppp[52460]: tun0: TCP/IP: route_UpdateMTU: Netif: 6 (tun0), dst ff01:6::/32, mtu 1500 Dec 11 17:14:57 fw ppp[52460]: tun0: ID0: 3 = socket(17, 3, 0) Dec 11 17:14:57 fw ppp[52460]: tun0: ID0: 188 = write(3, data, 188) Dec 11 17:14:57 fw ppp[52460]: tun0: TCP/IP: route_UpdateMTU: Netif: 6 (tun0), dst ff02:6::/32, mtu 1500 Dec 11 17:14:57 fw ppp[52460]: tun0: ID0: 3 = socket(17, 3, 0) Dec 11 17:14:57 fw ppp[52460]: tun0: ID0: 188 = write(3, data, 188) Dec 11 17:14:57 fw ppp[52460]: tun0: IPCP: deflink: LayerDown: WWW.XXX.YYY.ZZZ Dec 11 17:14:57 fw ppp[52460]: tun0: ID0: 0x0 = fopen("/etc/ppp/ppp.linkdown", "r") Dec 11 17:14:57 fw ppp[52460]: tun0: Debug: ReadSystem: Can't open /etc/ppp/ppp.linkdown. Dec 11 17:14:57 fw ppp[52460]: tun0: ID0: 0x0 = fopen("/etc/ppp/ppp.linkdown", "r") Dec 11 17:14:57 fw ppp[52460]: tun0: Debug: ReadSystem: Can't open /etc/ppp/ppp.linkdown. Dec 11 17:14:57 fw ppp[52460]: tun0: ID0: 0x0 = fopen("/etc/ppp/ppp.linkdown", "r") Dec 11 17:14:57 fw ppp[52460]: tun0: Debug: ReadSystem: Can't open /etc/ppp/ppp.linkdown. Dec 11 17:14:57 fw ppp[52460]: tun0: IPCP: Using trigger address 0.0.0.0 Dec 11 17:14:57 fw ppp[52460]: tun0: IPCP: deflink: State change Opened --> Starting Dec 11 17:14:57 fw ppp[52460]: tun0: IPCP: deflink: LayerFinish. Dec 11 17:14:57 fw ppp[52460]: tun0: IPCP: Connect time: 86399 secs: 2329766345 octets in, 578411596 octets out Dec 11 17:14:57 fw ppp[52460]: tun0: IPCP: 5136910 packets in, 4516604 packets out Dec 11 17:14:57 fw ppp[52460]: tun0: IPCP: total 33659 bytes/sec, peak 141368 bytes/sec on Mon Dec 10 17:24:52 2007 Dec 11 17:14:57 fw ppp[52460]: tun0: IPCP: deflink: State change Starting --> Initial Dec 11 17:14:57 fw ppp[52460]: tun0: Phase: bundle: Terminate Dec 11 17:14:57 fw ppp[52460]: tun0: IPV6CP: deflink: State change Closed --> Initial Dec 11 17:14:57 fw ppp[52460]: tun0: LCP: deflink: LayerFinish Dec 11 17:14:57 fw ppp[52460]: tun0: LCP: deflink: State change Starting --> Initial Dec 11 17:14:57 fw ppp[52460]: tun0: Phase: deflink: Disconnected! Dec 11 17:14:57 fw ppp[52460]: tun0: Phase: deflink: lcp -> logout Dec 11 17:14:57 fw ppp[52460]: tun0: Phase: deflink: Disconnected! Dec 11 17:14:57 fw ppp[52460]: tun0: Phase: deflink: logout -> hangup Dec 11 17:14:57 fw ppp[52460]: tun0: Debug: m_enqueue: len = 1 Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:57 fw ppp[52460]: tun0: Debug: deflink: Close Dec 11 17:14:57 fw ppp[52460]: tun0: Phase: deflink: Connect time: 86404 secs: 2323697100 octets in, 583841050 octets out Dec 11 17:14:57 fw ppp[52460]: tun0: Phase: deflink: 5159567 packets in, 4539264 packets out Dec 11 17:14:57 fw ppp[52460]: tun0: Phase: total 33650 bytes/sec, peak 141561 bytes/sec on Mon Dec 10 17:24:53 2007 Dec 11 17:14:57 fw ppp[52460]: tun0: Phase: deflink: hangup -> closed Dec 11 17:14:57 fw ppp[52460]: tun0: Phase: bundle: Dead Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: timer_Start: Inserting dial timer[0x80b9d44] Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:14:57 fw ppp[52460]: tun0: Phase: bundle: Establish Dec 11 17:14:57 fw ppp[52460]: tun0: Phase: deflink: closed -> opening Dec 11 17:14:57 fw ppp[52460]: tun0: Debug: m_enqueue: len = 2 Dec 11 17:14:57 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:57 fw ppp[52460]: tun0: ID0: 0 = NgMkSockNode("", &cs, &ds) Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: List of netgraph node ``sis0:'' (id 1) hooks: Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Found orphans -> ethernet Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Connecting netgraph socket .:tun0 -> [5]::tun0 Dec 11 17:14:58 fw ppp[52460]: tun0: ID0: 3 = socket(2, 2, 0) Dec 11 17:14:58 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 3223349521, 0xbfbfdd80) Dec 11 17:14:58 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 2149607696, 0xbfbfdd80) Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Sending PPPOE_CONNECT to .:tun0 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: timer_Start: Inserting physical throughput timer[0x80bb068] Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: Connected! Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: opening -> dial Dec 11 17:14:58 fw ppp[52460]: tun0: Chat: deflink: Dial attempt 1 of 1 Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: dial -> carrier Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: m_enqueue: len = 3 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: m_enqueue: len = 4 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: m_enqueue: len = 5 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: m_enqueue: len = 6 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: m_enqueue: len = 7 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: Disconnected! Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: carrier -> hangup Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: deflink: Close Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: Connect time: 0 secs: 0 octets in, 0 octets out Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: 5159567 packets in, 4539264 packets out Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: total 0 bytes/sec, peak 0 bytes/sec on Tue Dec 11 17:14:58 2007 Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: hangup -> closed Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: bundle: Dead Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: timer_Start: Inserting dial timer[0x80b9d44] Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: bundle: Establish Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: closed -> opening Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: m_enqueue: len = 8 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:58 fw ppp[52460]: tun0: ID0: 0 = NgMkSockNode("", &cs, &ds) Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: List of netgraph node ``sis0:'' (id 1) hooks: Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Found orphans -> ethernet Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Connecting netgraph socket .:tun0 -> [5]::tun0 Dec 11 17:14:58 fw ppp[52460]: tun0: ID0: 3 = socket(2, 2, 0) Dec 11 17:14:58 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 3223349521, 0xbfbfdd80) Dec 11 17:14:58 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 2149607696, 0xbfbfdd80) Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Sending PPPOE_CONNECT to .:tun0 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: timer_Start: Inserting physical throughput timer[0x80bb068] Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: Connected! Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: opening -> dial Dec 11 17:14:58 fw ppp[52460]: tun0: Chat: deflink: Dial attempt 1 of 1 Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: dial -> carrier Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: m_enqueue: len = 9 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: m_enqueue: len = 10 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: m_enqueue: len = 11 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: m_enqueue: len = 12 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: m_enqueue: len = 13 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: Disconnected! Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: carrier -> hangup Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: deflink: Close Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: Connect time: 0 secs: 0 octets in, 0 octets out Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: 5159567 packets in, 4539264 packets out Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: total 0 bytes/sec, peak 0 bytes/sec on Tue Dec 11 17:14:58 2007 Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: hangup -> closed Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: bundle: Dead Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: timer_Start: Inserting dial timer[0x80b9d44] Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: bundle: Establish Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: closed -> opening Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: m_enqueue: len = 14 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:58 fw ppp[52460]: tun0: ID0: 0 = NgMkSockNode("", &cs, &ds) Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: List of netgraph node ``sis0:'' (id 1) hooks: Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Found orphans -> ethernet Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Connecting netgraph socket .:tun0 -> [5]::tun0 Dec 11 17:14:58 fw ppp[52460]: tun0: ID0: 3 = socket(2, 2, 0) Dec 11 17:14:58 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 3223349521, 0xbfbfdd80) Dec 11 17:14:58 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 2149607696, 0xbfbfdd80) Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Sending PPPOE_CONNECT to .:tun0 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: timer_Start: Inserting physical throughput timer[0x80bb068] Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: Connected! Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: opening -> dial Dec 11 17:14:58 fw ppp[52460]: tun0: Chat: deflink: Dial attempt 1 of 1 Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: dial -> carrier Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: m_enqueue: len = 15 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: m_enqueue: len = 16 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: m_enqueue: len = 17 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: m_enqueue: len = 18 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: m_enqueue: len = 19 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: Disconnected! Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: carrier -> hangup Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: deflink: Close Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: Connect time: 0 secs: 0 octets in, 0 octets out Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: 5159567 packets in, 4539264 packets out Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: total 0 bytes/sec, peak 0 bytes/sec on Tue Dec 11 17:14:58 2007 Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: hangup -> closed Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: bundle: Dead Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: timer_Start: Inserting dial timer[0x80b9d44] Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: bundle: Establish Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: closed -> opening Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: m_enqueue: len = 20 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:58 fw ppp[52460]: tun0: ID0: 0 = NgMkSockNode("", &cs, &ds) Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: List of netgraph node ``sis0:'' (id 1) hooks: Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Found orphans -> ethernet Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Connecting netgraph socket .:tun0 -> [5]::tun0 Dec 11 17:14:58 fw ppp[52460]: tun0: ID0: 3 = socket(2, 2, 0) Dec 11 17:14:58 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 3223349521, 0xbfbfdd80) Dec 11 17:14:58 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 2149607696, 0xbfbfdd80) Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Sending PPPOE_CONNECT to .:tun0 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: timer_Start: Inserting physical throughput timer[0x80bb068] Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: Connected! Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: opening -> dial Dec 11 17:14:58 fw ppp[52460]: tun0: Chat: deflink: Dial attempt 1 of 1 Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: dial -> carrier Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: m_enqueue: len = 21 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: m_enqueue: len = 22 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: m_enqueue: len = 23 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: m_enqueue: len = 24 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: m_enqueue: len = 25 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: Disconnected! Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: carrier -> hangup Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: deflink: Close Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: Connect time: 0 secs: 0 octets in, 0 octets out Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: 5159567 packets in, 4539264 packets out Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: total 0 bytes/sec, peak 0 bytes/sec on Tue Dec 11 17:14:58 2007 Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: hangup -> closed Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: bundle: Dead Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: timer_Start: Inserting dial timer[0x80b9d44] Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: bundle: Establish Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: closed -> opening Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: m_enqueue: len = 26 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:58 fw ppp[52460]: tun0: ID0: 0 = NgMkSockNode("", &cs, &ds) Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: List of netgraph node ``sis0:'' (id 1) hooks: Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Found orphans -> ethernet Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Connecting netgraph socket .:tun0 -> [5]::tun0 Dec 11 17:14:58 fw ppp[52460]: tun0: ID0: 3 = socket(2, 2, 0) Dec 11 17:14:58 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 3223349521, 0xbfbfdd80) Dec 11 17:14:58 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 2149607696, 0xbfbfdd80) Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Sending PPPOE_CONNECT to .:tun0 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: timer_Start: Inserting physical throughput timer[0x80bb068] Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: Connected! Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: opening -> dial Dec 11 17:14:58 fw ppp[52460]: tun0: Chat: deflink: Dial attempt 1 of 1 Dec 11 17:14:58 fw ppp[52460]: tun0: Phase: deflink: dial -> carrier Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: m_enqueue: len = 27 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: m_enqueue: len = 28 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: m_enqueue: len = 29 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: timer_Start: Inserting output choke timer[0x80ad520] Dec 11 17:14:58 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:58 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:14:59 fw ppp[52460]: tun0: Timer: Select returns -1 Dec 11 17:14:59 fw ppp[52460]: tun0: Timer: ---- Begin of Timer Service List--- Dec 11 17:14:59 fw ppp[52460]: tun0: Timer: physical throughput timer[0x80bb068]: freq = 1.00s, next = 0.00s, state = running Dec 11 17:14:59 fw ppp[52460]: tun0: Timer: output choke timer[0x80ad520]: freq = 120.00s, next = 119.30s, state = running Dec 11 17:14:59 fw ppp[52460]: tun0: Timer: ---- End of Timer Service List --- Dec 11 17:14:59 fw ppp[52460]: tun0: Timer: timer_Start: Inserting physical throughput timer[0x80bb068] before output choke timer[0x80ad520], delta = 10 Dec 11 17:14:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:14:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:14:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:15:00 fw ppp[52460]: tun0: Timer: Select returns -1 Dec 11 17:15:00 fw ppp[52460]: tun0: Timer: ---- Begin of Timer Service List--- Dec 11 17:15:00 fw ppp[52460]: tun0: Timer: physical throughput timer[0x80bb068]: freq = 1.00s, next = 0.00s, state = running Dec 11 17:15:00 fw ppp[52460]: tun0: Timer: output choke timer[0x80ad520]: freq = 120.00s, next = 118.30s, state = running Dec 11 17:15:00 fw ppp[52460]: tun0: Timer: ---- End of Timer Service List --- Dec 11 17:15:00 fw ppp[52460]: tun0: Timer: timer_Start: Inserting physical throughput timer[0x80bb068] before output choke timer[0x80ad520], delta = 10 Dec 11 17:15:00 fw ppp[52460]: tun0: Phase: deflink: Disconnected! Dec 11 17:15:00 fw ppp[52460]: tun0: Phase: deflink: carrier -> hangup Dec 11 17:15:00 fw ppp[52460]: tun0: Debug: deflink: Close Dec 11 17:15:00 fw ppp[52460]: tun0: Phase: deflink: Connect time: 2 secs: 0 octets in, 0 octets out Dec 11 17:15:00 fw ppp[52460]: tun0: Phase: deflink: 5159567 packets in, 4539264 packets out Dec 11 17:15:00 fw ppp[52460]: tun0: Phase: total 0 bytes/sec, peak 0 bytes/sec on Tue Dec 11 17:14:58 2007 Dec 11 17:15:00 fw ppp[52460]: tun0: Phase: deflink: hangup -> closed Dec 11 17:15:00 fw ppp[52460]: tun0: Phase: bundle: Dead Dec 11 17:15:00 fw ppp[52460]: tun0: Timer: timer_Start: Inserting dial timer[0x80b9d44] before output choke timer[0x80ad520], delta = 300 Dec 11 17:15:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:15:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:15:30 fw ppp[52460]: tun0: Timer: Select returns -1 Dec 11 17:15:30 fw ppp[52460]: tun0: Timer: ---- Begin of Timer Service List--- Dec 11 17:15:30 fw ppp[52460]: tun0: Timer: dial timer[0x80b9d44]: freq = 30.00s, next = 0.00s, state = running Dec 11 17:15:30 fw ppp[52460]: tun0: Timer: output choke timer[0x80ad520]: freq = 120.00s, next = 88.30s, state = running Dec 11 17:15:30 fw ppp[52460]: tun0: Timer: ---- End of Timer Service List --- Dec 11 17:15:30 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:15:30 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:16:58 fw ppp[52460]: tun0: Timer: Select returns -1 Dec 11 17:16:58 fw ppp[52460]: tun0: Timer: ---- Begin of Timer Service List--- Dec 11 17:16:58 fw ppp[52460]: tun0: Timer: output choke timer[0x80ad520]: freq = 120.00s, next = 0.00s, state = running Dec 11 17:16:58 fw ppp[52460]: tun0: Timer: ---- End of Timer Service List --- Dec 11 17:16:58 fw ppp[52460]: tun0: Phase: Clearing choked output queue Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 29 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 28 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 27 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 26 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 25 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 24 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 23 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 22 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 21 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 20 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 19 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 18 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 17 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 16 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 15 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 14 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 13 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 12 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 11 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 10 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 9 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 8 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 7 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 6 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 5 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 4 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 3 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 2 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 1 Dec 11 17:16:58 fw last message repeated 2 times Dec 11 17:16:58 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:16:58 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:16:58 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:16:58 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:16:58 fw ppp[52460]: tun0: Phase: bundle: Establish Dec 11 17:16:58 fw ppp[52460]: tun0: Phase: deflink: closed -> opening Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: m_enqueue: len = 1 Dec 11 17:16:58 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:16:58 fw ppp[52460]: tun0: ID0: 0 = NgMkSockNode("", &cs, &ds) Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: List of netgraph node ``sis0:'' (id 1) hooks: Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: Found orphans -> ethernet Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: Connecting netgraph socket .:tun0 -> [5]::tun0 Dec 11 17:16:58 fw ppp[52460]: tun0: ID0: 3 = socket(2, 2, 0) Dec 11 17:16:58 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 3223349521, 0xbfbfdd80) Dec 11 17:16:58 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 2149607696, 0xbfbfdd80) Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: Sending PPPOE_CONNECT to .:tun0 Dec 11 17:16:58 fw ppp[52460]: tun0: Timer: timer_Start: Inserting physical throughput timer[0x80bb068] Dec 11 17:16:58 fw ppp[52460]: tun0: Phase: deflink: Connected! Dec 11 17:16:58 fw ppp[52460]: tun0: Phase: deflink: opening -> dial Dec 11 17:16:58 fw ppp[52460]: tun0: Chat: deflink: Dial attempt 1 of 1 Dec 11 17:16:58 fw ppp[52460]: tun0: Phase: deflink: dial -> carrier Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:16:58 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:16:58 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:16:58 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: m_enqueue: len = 2 Dec 11 17:16:58 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:16:58 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:16:58 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:16:58 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: m_enqueue: len = 3 Dec 11 17:16:58 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:16:58 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:16:58 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:16:58 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: m_enqueue: len = 4 Dec 11 17:16:58 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:16:58 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:16:58 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:16:58 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: m_enqueue: len = 5 Dec 11 17:16:58 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:16:58 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:16:58 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:16:58 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:16:58 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 6 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: Disconnected! Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: carrier -> hangup Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: deflink: Close Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: Connect time: 1 secs: 0 octets in, 0 octets out Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: 5159567 packets in, 4539264 packets out Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: total 0 bytes/sec, peak 0 bytes/sec on Tue Dec 11 17:16:58 2007 Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: hangup -> closed Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: bundle: Dead Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: timer_Start: Inserting dial timer[0x80b9d44] Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: bundle: Establish Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: closed -> opening Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 7 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:16:59 fw ppp[52460]: tun0: ID0: 0 = NgMkSockNode("", &cs, &ds) Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: List of netgraph node ``sis0:'' (id 1) hooks: Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: Found orphans -> ethernet Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: Connecting netgraph socket .:tun0 -> [5]::tun0 Dec 11 17:16:59 fw ppp[52460]: tun0: ID0: 3 = socket(2, 2, 0) Dec 11 17:16:59 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 3223349521, 0xbfbfdd80) Dec 11 17:16:59 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 2149607696, 0xbfbfdd80) Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: Sending PPPOE_CONNECT to .:tun0 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: timer_Start: Inserting physical throughput timer[0x80bb068] Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: Connected! Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: opening -> dial Dec 11 17:16:59 fw ppp[52460]: tun0: Chat: deflink: Dial attempt 1 of 1 Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: dial -> carrier Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 8 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 9 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 10 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 11 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 12 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: Disconnected! Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: carrier -> hangup Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: deflink: Close Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: Connect time: 0 secs: 0 octets in, 0 octets out Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: 5159567 packets in, 4539264 packets out Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: total 0 bytes/sec, peak 0 bytes/sec on Tue Dec 11 17:16:59 2007 Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: hangup -> closed Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: bundle: Dead Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: timer_Start: Inserting dial timer[0x80b9d44] Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: bundle: Establish Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: closed -> opening Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 13 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:16:59 fw ppp[52460]: tun0: ID0: 0 = NgMkSockNode("", &cs, &ds) Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: List of netgraph node ``sis0:'' (id 1) hooks: Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: Found orphans -> ethernet Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: Connecting netgraph socket .:tun0 -> [5]::tun0 Dec 11 17:16:59 fw ppp[52460]: tun0: ID0: 3 = socket(2, 2, 0) Dec 11 17:16:59 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 3223349521, 0xbfbfdd80) Dec 11 17:16:59 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 2149607696, 0xbfbfdd80) Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: Sending PPPOE_CONNECT to .:tun0 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: timer_Start: Inserting physical throughput timer[0x80bb068] Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: Connected! Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: opening -> dial Dec 11 17:16:59 fw ppp[52460]: tun0: Chat: deflink: Dial attempt 1 of 1 Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: dial -> carrier Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 14 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 15 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 16 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 17 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 18 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: Disconnected! Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: carrier -> hangup Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: deflink: Close Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: Connect time: 0 secs: 0 octets in, 0 octets out Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: 5159567 packets in, 4539264 packets out Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: total 0 bytes/sec, peak 0 bytes/sec on Tue Dec 11 17:16:59 2007 Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: hangup -> closed Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: bundle: Dead Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: timer_Start: Inserting dial timer[0x80b9d44] Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: bundle: Establish Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: closed -> opening Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 19 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:16:59 fw ppp[52460]: tun0: ID0: 0 = NgMkSockNode("", &cs, &ds) Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: List of netgraph node ``sis0:'' (id 1) hooks: Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: Found orphans -> ethernet Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: Connecting netgraph socket .:tun0 -> [5]::tun0 Dec 11 17:16:59 fw ppp[52460]: tun0: ID0: 3 = socket(2, 2, 0) Dec 11 17:16:59 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 3223349521, 0xbfbfdd80) Dec 11 17:16:59 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 2149607696, 0xbfbfdd80) Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: Sending PPPOE_CONNECT to .:tun0 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: timer_Start: Inserting physical throughput timer[0x80bb068] Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: Connected! Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: opening -> dial Dec 11 17:16:59 fw ppp[52460]: tun0: Chat: deflink: Dial attempt 1 of 1 Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: dial -> carrier Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 20 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 21 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 22 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 23 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 24 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: Disconnected! Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: carrier -> hangup Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: deflink: Close Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: Connect time: 0 secs: 0 octets in, 0 octets out Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: 5159567 packets in, 4539264 packets out Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: total 0 bytes/sec, peak 0 bytes/sec on Tue Dec 11 17:16:59 2007 Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: hangup -> closed Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: bundle: Dead Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: timer_Start: Inserting dial timer[0x80b9d44] Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: bundle: Establish Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: closed -> opening Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 25 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:16:59 fw ppp[52460]: tun0: ID0: 0 = NgMkSockNode("", &cs, &ds) Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: List of netgraph node ``sis0:'' (id 1) hooks: Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: Found orphans -> ethernet Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: Connecting netgraph socket .:tun0 -> [5]::tun0 Dec 11 17:16:59 fw ppp[52460]: tun0: ID0: 3 = socket(2, 2, 0) Dec 11 17:16:59 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 3223349521, 0xbfbfdd80) Dec 11 17:16:59 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 2149607696, 0xbfbfdd80) Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: Sending PPPOE_CONNECT to .:tun0 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: timer_Start: Inserting physical throughput timer[0x80bb068] Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: Connected! Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: opening -> dial Dec 11 17:16:59 fw ppp[52460]: tun0: Chat: deflink: Dial attempt 1 of 1 Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: dial -> carrier Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 26 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 27 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 28 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 29 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 30 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: timer_Start: Inserting output choke timer[0x80ad520] Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: Disconnected! Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: carrier -> hangup Dec 11 17:16:59 fw ppp[52460]: tun0: Debug: deflink: Close Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: Connect time: 0 secs: 0 octets in, 0 octets out Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: 5159567 packets in, 4539264 packets out Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: total 0 bytes/sec, peak 0 bytes/sec on Tue Dec 11 17:16:59 2007 Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: deflink: hangup -> closed Dec 11 17:16:59 fw ppp[52460]: tun0: Phase: bundle: Dead Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: timer_Start: Inserting dial timer[0x80b9d44] before output choke timer[0x80ad520], delta = 300 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:16:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:17:29 fw ppp[52460]: tun0: Timer: Select returns -1 Dec 11 17:17:29 fw ppp[52460]: tun0: Timer: ---- Begin of Timer Service List--- Dec 11 17:17:29 fw ppp[52460]: tun0: Timer: dial timer[0x80b9d44]: freq = 30.00s, next = 0.00s, state = running Dec 11 17:17:29 fw ppp[52460]: tun0: Timer: output choke timer[0x80ad520]: freq = 120.00s, next = 90.00s, state = running Dec 11 17:17:29 fw ppp[52460]: tun0: Timer: ---- End of Timer Service List --- Dec 11 17:17:29 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:17:29 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: Select returns -1 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: ---- Begin of Timer Service List--- Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: output choke timer[0x80ad520]: freq = 120.00s, next = 0.00s, state = running Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: ---- End of Timer Service List --- Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: Clearing choked output queue Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 30 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 29 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 28 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 27 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 26 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 25 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 24 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 23 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 22 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 21 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 20 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 19 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 18 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 17 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 16 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 15 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 14 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 13 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 12 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 11 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 10 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 9 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 8 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 7 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 6 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 5 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 4 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 3 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 2 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 1 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: bundle: Establish Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: deflink: closed -> opening Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 1 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:18:59 fw ppp[52460]: tun0: ID0: 0 = NgMkSockNode("", &cs, &ds) Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: List of netgraph node ``sis0:'' (id 1) hooks: Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: Found orphans -> ethernet Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: Connecting netgraph socket .:tun0 -> [5]::tun0 Dec 11 17:18:59 fw ppp[52460]: tun0: ID0: 3 = socket(2, 2, 0) Dec 11 17:18:59 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 3223349521, 0xbfbfdd80) Dec 11 17:18:59 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 2149607696, 0xbfbfdd80) Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: Sending PPPOE_CONNECT to .:tun0 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: timer_Start: Inserting physical throughput timer[0x80bb068] Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: deflink: Connected! Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: deflink: opening -> dial Dec 11 17:18:59 fw ppp[52460]: tun0: Chat: deflink: Dial attempt 1 of 1 Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: deflink: dial -> carrier Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 2 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 3 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 4 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 5 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 6 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: deflink: Disconnected! Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: deflink: carrier -> hangup Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: deflink: Close Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: deflink: Connect time: 0 secs: 0 octets in, 0 octets out Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: deflink: 5159567 packets in, 4539264 packets out Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: total 0 bytes/sec, peak 0 bytes/sec on Tue Dec 11 17:18:59 2007 Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: deflink: hangup -> closed Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: bundle: Dead Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: timer_Start: Inserting dial timer[0x80b9d44] Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: bundle: Establish Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: deflink: closed -> opening Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 7 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:18:59 fw ppp[52460]: tun0: ID0: 0 = NgMkSockNode("", &cs, &ds) Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: List of netgraph node ``sis0:'' (id 1) hooks: Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: Found orphans -> ethernet Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: Connecting netgraph socket .:tun0 -> [5]::tun0 Dec 11 17:18:59 fw ppp[52460]: tun0: ID0: 3 = socket(2, 2, 0) Dec 11 17:18:59 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 3223349521, 0xbfbfdd80) Dec 11 17:18:59 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 2149607696, 0xbfbfdd80) Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: Sending PPPOE_CONNECT to .:tun0 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: timer_Start: Inserting physical throughput timer[0x80bb068] Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: deflink: Connected! Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: deflink: opening -> dial Dec 11 17:18:59 fw ppp[52460]: tun0: Chat: deflink: Dial attempt 1 of 1 Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: deflink: dial -> carrier Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 8 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 9 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 10 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 11 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 12 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: deflink: Disconnected! Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: deflink: carrier -> hangup Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: deflink: Close Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: deflink: Connect time: 0 secs: 0 octets in, 0 octets out Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: deflink: 5159567 packets in, 4539264 packets out Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: total 0 bytes/sec, peak 0 bytes/sec on Tue Dec 11 17:18:59 2007 Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: deflink: hangup -> closed Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: bundle: Dead Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: timer_Start: Inserting dial timer[0x80b9d44] Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: bundle: Establish Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: deflink: closed -> opening Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 13 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:18:59 fw ppp[52460]: tun0: ID0: 0 = NgMkSockNode("", &cs, &ds) Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: List of netgraph node ``sis0:'' (id 1) hooks: Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: Found orphans -> ethernet Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: Connecting netgraph socket .:tun0 -> [5]::tun0 Dec 11 17:18:59 fw ppp[52460]: tun0: ID0: 3 = socket(2, 2, 0) Dec 11 17:18:59 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 3223349521, 0xbfbfdd80) Dec 11 17:18:59 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 2149607696, 0xbfbfdd80) Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: Sending PPPOE_CONNECT to .:tun0 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: timer_Start: Inserting physical throughput timer[0x80bb068] Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: deflink: Connected! Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: deflink: opening -> dial Dec 11 17:18:59 fw ppp[52460]: tun0: Chat: deflink: Dial attempt 1 of 1 Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: deflink: dial -> carrier Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 14 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 15 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 16 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 17 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 18 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: deflink: Disconnected! Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: deflink: carrier -> hangup Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: deflink: Close Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: deflink: Connect time: 0 secs: 0 octets in, 0 octets out Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: deflink: 5159567 packets in, 4539264 packets out Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: total 0 bytes/sec, peak 0 bytes/sec on Tue Dec 11 17:18:59 2007 Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: deflink: hangup -> closed Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: bundle: Dead Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: timer_Start: Inserting dial timer[0x80b9d44] Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: bundle: Establish Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: deflink: closed -> opening Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 19 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:18:59 fw ppp[52460]: tun0: ID0: 0 = NgMkSockNode("", &cs, &ds) Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: List of netgraph node ``sis0:'' (id 1) hooks: Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: Found orphans -> ethernet Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: Connecting netgraph socket .:tun0 -> [5]::tun0 Dec 11 17:18:59 fw ppp[52460]: tun0: ID0: 3 = socket(2, 2, 0) Dec 11 17:18:59 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 3223349521, 0xbfbfdd80) Dec 11 17:18:59 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 2149607696, 0xbfbfdd80) Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: Sending PPPOE_CONNECT to .:tun0 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: timer_Start: Inserting physical throughput timer[0x80bb068] Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: deflink: Connected! Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: deflink: opening -> dial Dec 11 17:18:59 fw ppp[52460]: tun0: Chat: deflink: Dial attempt 1 of 1 Dec 11 17:18:59 fw ppp[52460]: tun0: Phase: deflink: dial -> carrier Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: m_enqueue: len = 20 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:18:59 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:18:59 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:19:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 21 Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:19:00 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:19:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 22 Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:19:00 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:19:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 23 Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:19:00 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:19:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 24 Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:19:00 fw ppp[52460]: tun0: Phase: deflink: Disconnected! Dec 11 17:19:00 fw ppp[52460]: tun0: Phase: deflink: carrier -> hangup Dec 11 17:19:00 fw ppp[52460]: tun0: Debug: deflink: Close Dec 11 17:19:00 fw ppp[52460]: tun0: Phase: deflink: Connect time: 1 secs: 0 octets in, 0 octets out Dec 11 17:19:00 fw ppp[52460]: tun0: Phase: deflink: 5159567 packets in, 4539264 packets out Dec 11 17:19:00 fw ppp[52460]: tun0: Phase: total 0 bytes/sec, peak 0 bytes/sec on Tue Dec 11 17:18:59 2007 Dec 11 17:19:00 fw ppp[52460]: tun0: Phase: deflink: hangup -> closed Dec 11 17:19:00 fw ppp[52460]: tun0: Phase: bundle: Dead Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: timer_Start: Inserting dial timer[0x80b9d44] Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:19:00 fw ppp[52460]: tun0: Phase: bundle: Establish Dec 11 17:19:00 fw ppp[52460]: tun0: Phase: deflink: closed -> opening Dec 11 17:19:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 25 Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:19:00 fw ppp[52460]: tun0: ID0: 0 = NgMkSockNode("", &cs, &ds) Dec 11 17:19:00 fw ppp[52460]: tun0: Debug: List of netgraph node ``sis0:'' (id 1) hooks: Dec 11 17:19:00 fw ppp[52460]: tun0: Debug: Found orphans -> ethernet Dec 11 17:19:00 fw ppp[52460]: tun0: Debug: Connecting netgraph socket .:tun0 -> [5]::tun0 Dec 11 17:19:00 fw ppp[52460]: tun0: ID0: 3 = socket(2, 2, 0) Dec 11 17:19:00 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 3223349521, 0xbfbfdd80) Dec 11 17:19:00 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 2149607696, 0xbfbfdd80) Dec 11 17:19:00 fw ppp[52460]: tun0: Debug: Sending PPPOE_CONNECT to .:tun0 Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: timer_Start: Inserting physical throughput timer[0x80bb068] Dec 11 17:19:00 fw ppp[52460]: tun0: Phase: deflink: Connected! Dec 11 17:19:00 fw ppp[52460]: tun0: Phase: deflink: opening -> dial Dec 11 17:19:00 fw ppp[52460]: tun0: Chat: deflink: Dial attempt 1 of 1 Dec 11 17:19:00 fw ppp[52460]: tun0: Phase: deflink: dial -> carrier Dec 11 17:19:00 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:19:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 26 Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:19:00 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:19:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 27 Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:19:00 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:19:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 28 Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:19:00 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:19:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 29 Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:19:00 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:19:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 30 Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: timer_Start: Inserting output choke timer[0x80ad520] Dec 11 17:19:00 fw ppp[52460]: tun0: Phase: deflink: Disconnected! Dec 11 17:19:00 fw ppp[52460]: tun0: Phase: deflink: carrier -> hangup Dec 11 17:19:00 fw ppp[52460]: tun0: Debug: deflink: Close Dec 11 17:19:00 fw ppp[52460]: tun0: Phase: deflink: Connect time: 0 secs: 0 octets in, 0 octets out Dec 11 17:19:00 fw ppp[52460]: tun0: Phase: deflink: 5159567 packets in, 4539264 packets out Dec 11 17:19:00 fw ppp[52460]: tun0: Phase: total 0 bytes/sec, peak 0 bytes/sec on Tue Dec 11 17:19:00 2007 Dec 11 17:19:00 fw ppp[52460]: tun0: Phase: deflink: hangup -> closed Dec 11 17:19:00 fw ppp[52460]: tun0: Phase: bundle: Dead Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: timer_Start: Inserting dial timer[0x80b9d44] before output choke timer[0x80ad520], delta = 300 Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:19:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:19:30 fw ppp[52460]: tun0: Timer: Select returns -1 Dec 11 17:19:30 fw ppp[52460]: tun0: Timer: ---- Begin of Timer Service List--- Dec 11 17:19:30 fw ppp[52460]: tun0: Timer: dial timer[0x80b9d44]: freq = 30.00s, next = 0.00s, state = running Dec 11 17:19:30 fw ppp[52460]: tun0: Timer: output choke timer[0x80ad520]: freq = 120.00s, next = 90.00s, state = running Dec 11 17:19:30 fw ppp[52460]: tun0: Timer: ---- End of Timer Service List --- Dec 11 17:19:30 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:19:30 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: Select returns -1 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: ---- Begin of Timer Service List--- Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: output choke timer[0x80ad520]: freq = 120.00s, next = 0.00s, state = running Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: ---- End of Timer Service List --- Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: Clearing choked output queue Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 30 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 29 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 28 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 27 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 26 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 25 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 24 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 23 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 22 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 21 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 20 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 19 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 18 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 17 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 16 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 15 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 14 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 13 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 12 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 11 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 10 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 9 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 8 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 7 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 6 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 5 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 4 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 3 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 2 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: bundle: Establish Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: closed -> opening Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:21:00 fw ppp[52460]: tun0: ID0: 0 = NgMkSockNode("", &cs, &ds) Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: List of netgraph node ``sis0:'' (id 1) hooks: Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Found orphans -> ethernet Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Connecting netgraph socket .:tun0 -> [5]::tun0 Dec 11 17:21:00 fw ppp[52460]: tun0: ID0: 3 = socket(2, 2, 0) Dec 11 17:21:00 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 3223349521, 0xbfbfdd80) Dec 11 17:21:00 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 2149607696, 0xbfbfdd80) Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Sending PPPOE_CONNECT to .:tun0 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: timer_Start: Inserting physical throughput timer[0x80bb068] Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: Connected! Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: opening -> dial Dec 11 17:21:00 fw ppp[52460]: tun0: Chat: deflink: Dial attempt 1 of 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: dial -> carrier Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 2 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 3 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 4 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 5 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 6 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: Disconnected! Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: carrier -> hangup Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: deflink: Close Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: Connect time: 0 secs: 0 octets in, 0 octets out Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: 5159567 packets in, 4539264 packets out Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: total 0 bytes/sec, peak 0 bytes/sec on Tue Dec 11 17:21:00 2007 Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: hangup -> closed Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: bundle: Dead Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: timer_Start: Inserting dial timer[0x80b9d44] Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: bundle: Establish Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: closed -> opening Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 7 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:21:00 fw ppp[52460]: tun0: ID0: 0 = NgMkSockNode("", &cs, &ds) Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: List of netgraph node ``sis0:'' (id 1) hooks: Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Found orphans -> ethernet Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Connecting netgraph socket .:tun0 -> [5]::tun0 Dec 11 17:21:00 fw ppp[52460]: tun0: ID0: 3 = socket(2, 2, 0) Dec 11 17:21:00 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 3223349521, 0xbfbfdd80) Dec 11 17:21:00 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 2149607696, 0xbfbfdd80) Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Sending PPPOE_CONNECT to .:tun0 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: timer_Start: Inserting physical throughput timer[0x80bb068] Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: Connected! Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: opening -> dial Dec 11 17:21:00 fw ppp[52460]: tun0: Chat: deflink: Dial attempt 1 of 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: dial -> carrier Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 8 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 9 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 10 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 11 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 12 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: Disconnected! Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: carrier -> hangup Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: deflink: Close Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: Connect time: 0 secs: 0 octets in, 0 octets out Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: 5159567 packets in, 4539264 packets out Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: total 0 bytes/sec, peak 0 bytes/sec on Tue Dec 11 17:21:00 2007 Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: hangup -> closed Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: bundle: Dead Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: timer_Start: Inserting dial timer[0x80b9d44] Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: bundle: Establish Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: closed -> opening Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 13 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:21:00 fw ppp[52460]: tun0: ID0: 0 = NgMkSockNode("", &cs, &ds) Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: List of netgraph node ``sis0:'' (id 1) hooks: Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Found orphans -> ethernet Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Connecting netgraph socket .:tun0 -> [5]::tun0 Dec 11 17:21:00 fw ppp[52460]: tun0: ID0: 3 = socket(2, 2, 0) Dec 11 17:21:00 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 3223349521, 0xbfbfdd80) Dec 11 17:21:00 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 2149607696, 0xbfbfdd80) Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Sending PPPOE_CONNECT to .:tun0 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: timer_Start: Inserting physical throughput timer[0x80bb068] Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: Connected! Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: opening -> dial Dec 11 17:21:00 fw ppp[52460]: tun0: Chat: deflink: Dial attempt 1 of 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: dial -> carrier Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 14 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 15 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 16 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 17 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 18 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: Disconnected! Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: carrier -> hangup Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: deflink: Close Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: Connect time: 0 secs: 0 octets in, 0 octets out Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: 5159567 packets in, 4539264 packets out Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: total 0 bytes/sec, peak 0 bytes/sec on Tue Dec 11 17:21:00 2007 Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: hangup -> closed Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: bundle: Dead Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: timer_Start: Inserting dial timer[0x80b9d44] Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: bundle: Establish Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: closed -> opening Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 19 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:21:00 fw ppp[52460]: tun0: ID0: 0 = NgMkSockNode("", &cs, &ds) Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: List of netgraph node ``sis0:'' (id 1) hooks: Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Found orphans -> ethernet Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Connecting netgraph socket .:tun0 -> [5]::tun0 Dec 11 17:21:00 fw ppp[52460]: tun0: ID0: 3 = socket(2, 2, 0) Dec 11 17:21:00 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 3223349521, 0xbfbfdd80) Dec 11 17:21:00 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 2149607696, 0xbfbfdd80) Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Sending PPPOE_CONNECT to .:tun0 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: timer_Start: Inserting physical throughput timer[0x80bb068] Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: Connected! Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: opening -> dial Dec 11 17:21:00 fw ppp[52460]: tun0: Chat: deflink: Dial attempt 1 of 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: dial -> carrier Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 20 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 21 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 22 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 23 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 24 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: Disconnected! Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: carrier -> hangup Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: deflink: Close Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: Connect time: 0 secs: 0 octets in, 0 octets out Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: 5159567 packets in, 4539264 packets out Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: total 0 bytes/sec, peak 0 bytes/sec on Tue Dec 11 17:21:00 2007 Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: hangup -> closed Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: bundle: Dead Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: timer_Start: Inserting dial timer[0x80b9d44] Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: bundle: Establish Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: closed -> opening Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 25 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:21:00 fw ppp[52460]: tun0: ID0: 0 = NgMkSockNode("", &cs, &ds) Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: List of netgraph node ``sis0:'' (id 1) hooks: Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Found orphans -> ethernet Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Connecting netgraph socket .:tun0 -> [5]::tun0 Dec 11 17:21:00 fw ppp[52460]: tun0: ID0: 3 = socket(2, 2, 0) Dec 11 17:21:00 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 3223349521, 0xbfbfdd80) Dec 11 17:21:00 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 2149607696, 0xbfbfdd80) Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Sending PPPOE_CONNECT to .:tun0 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: timer_Start: Inserting physical throughput timer[0x80bb068] Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: Connected! Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: opening -> dial Dec 11 17:21:00 fw ppp[52460]: tun0: Chat: deflink: Dial attempt 1 of 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: dial -> carrier Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 26 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 27 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 28 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 29 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: m_enqueue: len = 30 Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: timer_Start: Inserting output choke timer[0x80ad520] Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: Disconnected! Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: carrier -> hangup Dec 11 17:21:00 fw ppp[52460]: tun0: Debug: deflink: Close Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: Connect time: 0 secs: 0 octets in, 0 octets out Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: 5159567 packets in, 4539264 packets out Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: total 0 bytes/sec, peak 0 bytes/sec on Tue Dec 11 17:21:00 2007 Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: deflink: hangup -> closed Dec 11 17:21:00 fw ppp[52460]: tun0: Phase: bundle: Dead Dec 11 17:21:00 fw ppp[52460]: tun0: Timer: timer_Start: Inserting dial timer[0x80b9d44] before output choke timer[0x80ad520], delta = 300 Dec 11 17:21:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:21:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:21:31 fw ppp[52460]: tun0: Timer: Select returns -1 Dec 11 17:21:31 fw ppp[52460]: tun0: Timer: ---- Begin of Timer Service List--- Dec 11 17:21:31 fw ppp[52460]: tun0: Timer: dial timer[0x80b9d44]: freq = 30.00s, next = 0.00s, state = running Dec 11 17:21:31 fw ppp[52460]: tun0: Timer: output choke timer[0x80ad520]: freq = 120.00s, next = 90.00s, state = running Dec 11 17:21:31 fw ppp[52460]: tun0: Timer: ---- End of Timer Service List --- Dec 11 17:21:31 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:21:31 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: Select returns -1 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: ---- Begin of Timer Service List--- Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: output choke timer[0x80ad520]: freq = 120.00s, next = 0.00s, state = running Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: ---- End of Timer Service List --- Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: Clearing choked output queue Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 30 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 29 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 28 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 27 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 26 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 25 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 24 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 23 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 22 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 21 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 20 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 19 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 18 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 17 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 16 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 15 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 14 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 13 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 12 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 11 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 10 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 9 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 8 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 7 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 6 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 5 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 4 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 3 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 2 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: bundle: Establish Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: closed -> opening Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:23:01 fw ppp[52460]: tun0: ID0: 0 = NgMkSockNode("", &cs, &ds) Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: List of netgraph node ``sis0:'' (id 1) hooks: Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Found orphans -> ethernet Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Connecting netgraph socket .:tun0 -> [5]::tun0 Dec 11 17:23:01 fw ppp[52460]: tun0: ID0: 3 = socket(2, 2, 0) Dec 11 17:23:01 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 3223349521, 0xbfbfdd80) Dec 11 17:23:01 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 2149607696, 0xbfbfdd80) Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Sending PPPOE_CONNECT to .:tun0 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: timer_Start: Inserting physical throughput timer[0x80bb068] Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: Connected! Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: opening -> dial Dec 11 17:23:01 fw ppp[52460]: tun0: Chat: deflink: Dial attempt 1 of 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: dial -> carrier Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 2 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 3 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 4 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 5 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 6 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: Disconnected! Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: carrier -> hangup Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: deflink: Close Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: Connect time: 0 secs: 0 octets in, 0 octets out Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: 5159567 packets in, 4539264 packets out Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: total 0 bytes/sec, peak 0 bytes/sec on Tue Dec 11 17:23:01 2007 Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: hangup -> closed Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: bundle: Dead Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: timer_Start: Inserting dial timer[0x80b9d44] Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: bundle: Establish Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: closed -> opening Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 7 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:23:01 fw ppp[52460]: tun0: ID0: 0 = NgMkSockNode("", &cs, &ds) Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: List of netgraph node ``sis0:'' (id 1) hooks: Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Found orphans -> ethernet Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Connecting netgraph socket .:tun0 -> [5]::tun0 Dec 11 17:23:01 fw ppp[52460]: tun0: ID0: 3 = socket(2, 2, 0) Dec 11 17:23:01 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 3223349521, 0xbfbfdd80) Dec 11 17:23:01 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 2149607696, 0xbfbfdd80) Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Sending PPPOE_CONNECT to .:tun0 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: timer_Start: Inserting physical throughput timer[0x80bb068] Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: Connected! Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: opening -> dial Dec 11 17:23:01 fw ppp[52460]: tun0: Chat: deflink: Dial attempt 1 of 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: dial -> carrier Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 8 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 9 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 10 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 11 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 12 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: Disconnected! Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: carrier -> hangup Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: deflink: Close Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: Connect time: 0 secs: 0 octets in, 0 octets out Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: 5159567 packets in, 4539264 packets out Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: total 0 bytes/sec, peak 0 bytes/sec on Tue Dec 11 17:23:01 2007 Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: hangup -> closed Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: bundle: Dead Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: timer_Start: Inserting dial timer[0x80b9d44] Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: bundle: Establish Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: closed -> opening Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 13 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:23:01 fw ppp[52460]: tun0: ID0: 0 = NgMkSockNode("", &cs, &ds) Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: List of netgraph node ``sis0:'' (id 1) hooks: Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Found orphans -> ethernet Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Connecting netgraph socket .:tun0 -> [5]::tun0 Dec 11 17:23:01 fw ppp[52460]: tun0: ID0: 3 = socket(2, 2, 0) Dec 11 17:23:01 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 3223349521, 0xbfbfdd80) Dec 11 17:23:01 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 2149607696, 0xbfbfdd80) Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Sending PPPOE_CONNECT to .:tun0 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: timer_Start: Inserting physical throughput timer[0x80bb068] Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: Connected! Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: opening -> dial Dec 11 17:23:01 fw ppp[52460]: tun0: Chat: deflink: Dial attempt 1 of 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: dial -> carrier Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 14 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 15 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 16 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 17 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 18 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: Disconnected! Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: carrier -> hangup Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: deflink: Close Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: Connect time: 0 secs: 0 octets in, 0 octets out Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: 5159567 packets in, 4539264 packets out Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: total 0 bytes/sec, peak 0 bytes/sec on Tue Dec 11 17:23:01 2007 Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: hangup -> closed Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: bundle: Dead Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: timer_Start: Inserting dial timer[0x80b9d44] Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: bundle: Establish Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: closed -> opening Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 19 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:23:01 fw ppp[52460]: tun0: ID0: 0 = NgMkSockNode("", &cs, &ds) Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: List of netgraph node ``sis0:'' (id 1) hooks: Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Found orphans -> ethernet Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Connecting netgraph socket .:tun0 -> [5]::tun0 Dec 11 17:23:01 fw ppp[52460]: tun0: ID0: 3 = socket(2, 2, 0) Dec 11 17:23:01 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 3223349521, 0xbfbfdd80) Dec 11 17:23:01 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 2149607696, 0xbfbfdd80) Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Sending PPPOE_CONNECT to .:tun0 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: timer_Start: Inserting physical throughput timer[0x80bb068] Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: Connected! Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: opening -> dial Dec 11 17:23:01 fw ppp[52460]: tun0: Chat: deflink: Dial attempt 1 of 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: dial -> carrier Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 20 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 21 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 22 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 23 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 24 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: Disconnected! Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: carrier -> hangup Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: deflink: Close Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: Connect time: 0 secs: 0 octets in, 0 octets out Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: 5159567 packets in, 4539264 packets out Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: total 0 bytes/sec, peak 0 bytes/sec on Tue Dec 11 17:23:01 2007 Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: hangup -> closed Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: bundle: Dead Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: timer_Start: Inserting dial timer[0x80b9d44] Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: bundle: Establish Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: closed -> opening Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 25 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:23:01 fw ppp[52460]: tun0: ID0: 0 = NgMkSockNode("", &cs, &ds) Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: List of netgraph node ``sis0:'' (id 1) hooks: Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Found orphans -> ethernet Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Connecting netgraph socket .:tun0 -> [5]::tun0 Dec 11 17:23:01 fw ppp[52460]: tun0: ID0: 3 = socket(2, 2, 0) Dec 11 17:23:01 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 3223349521, 0xbfbfdd80) Dec 11 17:23:01 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 2149607696, 0xbfbfdd80) Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Sending PPPOE_CONNECT to .:tun0 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: timer_Start: Inserting physical throughput timer[0x80bb068] Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: Connected! Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: opening -> dial Dec 11 17:23:01 fw ppp[52460]: tun0: Chat: deflink: Dial attempt 1 of 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: dial -> carrier Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 26 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 27 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 28 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 29 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 30 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: timer_Start: Inserting output choke timer[0x80ad520] Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: Disconnected! Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: carrier -> hangup Dec 11 17:23:01 fw ppp[52460]: tun0: Debug: deflink: Close Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: Connect time: 0 secs: 0 octets in, 0 octets out Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: 5159567 packets in, 4539264 packets out Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: total 0 bytes/sec, peak 0 bytes/sec on Tue Dec 11 17:23:01 2007 Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: deflink: hangup -> closed Dec 11 17:23:01 fw ppp[52460]: tun0: Phase: bundle: Dead Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: timer_Start: Inserting dial timer[0x80b9d44] before output choke timer[0x80ad520], delta = 300 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:23:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:23:31 fw ppp[52460]: tun0: Timer: Select returns -1 Dec 11 17:23:31 fw ppp[52460]: tun0: Timer: ---- Begin of Timer Service List--- Dec 11 17:23:31 fw ppp[52460]: tun0: Timer: dial timer[0x80b9d44]: freq = 30.00s, next = 0.00s, state = running Dec 11 17:23:31 fw ppp[52460]: tun0: Timer: output choke timer[0x80ad520]: freq = 120.00s, next = 90.00s, state = running Dec 11 17:23:31 fw ppp[52460]: tun0: Timer: ---- End of Timer Service List --- Dec 11 17:23:31 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:23:31 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:25:01 fw ppp[52460]: tun0: Timer: Select returns -1 Dec 11 17:25:01 fw ppp[52460]: tun0: Timer: ---- Begin of Timer Service List--- Dec 11 17:25:01 fw ppp[52460]: tun0: Timer: output choke timer[0x80ad520]: freq = 120.00s, next = 0.00s, state = running Dec 11 17:25:01 fw ppp[52460]: tun0: Timer: ---- End of Timer Service List --- Dec 11 17:25:01 fw ppp[52460]: tun0: Phase: Clearing choked output queue Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 30 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 29 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 28 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 27 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 26 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 25 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 24 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 23 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 22 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 21 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 20 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 19 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 18 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 17 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 16 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 15 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 14 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 13 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 12 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 11 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 10 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 9 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 8 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 7 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 6 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 5 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 4 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 3 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 2 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_dequeue: queue len = 1 Dec 11 17:25:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:25:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:25:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:25:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:25:01 fw ppp[52460]: tun0: Phase: bundle: Establish Dec 11 17:25:01 fw ppp[52460]: tun0: Phase: deflink: closed -> opening Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 1 Dec 11 17:25:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:25:01 fw ppp[52460]: tun0: ID0: 0 = NgMkSockNode("", &cs, &ds) Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: List of netgraph node ``sis0:'' (id 1) hooks: Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: Found orphans -> ethernet Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: Connecting netgraph socket .:tun0 -> [5]::tun0 Dec 11 17:25:01 fw ppp[52460]: tun0: ID0: 3 = socket(2, 2, 0) Dec 11 17:25:01 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 3223349521, 0xbfbfdd80) Dec 11 17:25:01 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 2149607696, 0xbfbfdd80) Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: Sending PPPOE_CONNECT to .:tun0 Dec 11 17:25:01 fw ppp[52460]: tun0: Timer: timer_Start: Inserting physical throughput timer[0x80bb068] Dec 11 17:25:01 fw ppp[52460]: tun0: Phase: deflink: Connected! Dec 11 17:25:01 fw ppp[52460]: tun0: Phase: deflink: opening -> dial Dec 11 17:25:01 fw ppp[52460]: tun0: Chat: deflink: Dial attempt 1 of 1 Dec 11 17:25:01 fw ppp[52460]: tun0: Phase: deflink: dial -> carrier Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:25:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:25:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:25:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 2 Dec 11 17:25:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:25:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:25:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:25:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 3 Dec 11 17:25:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:25:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:25:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:25:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 4 Dec 11 17:25:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:25:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:25:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:25:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 5 Dec 11 17:25:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:25:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:25:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:25:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: m_enqueue: len = 6 Dec 11 17:25:01 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:25:01 fw ppp[52460]: tun0: Phase: deflink: Disconnected! Dec 11 17:25:01 fw ppp[52460]: tun0: Phase: deflink: carrier -> hangup Dec 11 17:25:01 fw ppp[52460]: tun0: Debug: deflink: Close Dec 11 17:25:01 fw ppp[52460]: tun0: Phase: deflink: Connect time: 0 secs: 0 octets in, 0 octets out Dec 11 17:25:01 fw ppp[52460]: tun0: Phase: deflink: 5159567 packets in, 4539264 packets out Dec 11 17:25:01 fw ppp[52460]: tun0: Phase: total 0 bytes/sec, peak 0 bytes/sec on Tue Dec 11 17:25:01 2007 Dec 11 17:25:01 fw ppp[52460]: tun0: Phase: deflink: hangup -> closed Dec 11 17:25:01 fw ppp[52460]: tun0: Phase: bundle: Dead Dec 11 17:25:01 fw ppp[52460]: tun0: Timer: timer_Start: Inserting dial timer[0x80b9d44] Dec 11 17:25:01 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:25:01 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:25:01 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:25:01 fw ppp[52460]: tun0: Phase: bundle: Establish Dec 11 17:25:01 fw ppp[52460]: tun0: Phase: deflink: closed -> opening Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: m_enqueue: len = 7 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:25:02 fw ppp[52460]: tun0: ID0: 0 = NgMkSockNode("", &cs, &ds) Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: List of netgraph node ``sis0:'' (id 1) hooks: Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: Found orphans -> ethernet Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: Connecting netgraph socket .:tun0 -> [5]::tun0 Dec 11 17:25:02 fw ppp[52460]: tun0: ID0: 3 = socket(2, 2, 0) Dec 11 17:25:02 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 3223349521, 0xbfbfdd80) Dec 11 17:25:02 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 2149607696, 0xbfbfdd80) Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: Sending PPPOE_CONNECT to .:tun0 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: timer_Start: Inserting physical throughput timer[0x80bb068] Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: deflink: Connected! Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: deflink: opening -> dial Dec 11 17:25:02 fw ppp[52460]: tun0: Chat: deflink: Dial attempt 1 of 1 Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: deflink: dial -> carrier Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: m_enqueue: len = 8 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: m_enqueue: len = 9 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: m_enqueue: len = 10 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: m_enqueue: len = 11 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: m_enqueue: len = 12 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: deflink: Disconnected! Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: deflink: carrier -> hangup Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: deflink: Close Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: deflink: Connect time: 0 secs: 0 octets in, 0 octets out Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: deflink: 5159567 packets in, 4539264 packets out Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: total 0 bytes/sec, peak 0 bytes/sec on Tue Dec 11 17:25:02 2007 Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: deflink: hangup -> closed Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: bundle: Dead Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: timer_Start: Inserting dial timer[0x80b9d44] Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: bundle: Establish Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: deflink: closed -> opening Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: m_enqueue: len = 13 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:25:02 fw ppp[52460]: tun0: ID0: 0 = NgMkSockNode("", &cs, &ds) Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: List of netgraph node ``sis0:'' (id 1) hooks: Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: Found orphans -> ethernet Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: Connecting netgraph socket .:tun0 -> [5]::tun0 Dec 11 17:25:02 fw ppp[52460]: tun0: ID0: 3 = socket(2, 2, 0) Dec 11 17:25:02 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 3223349521, 0xbfbfdd80) Dec 11 17:25:02 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 2149607696, 0xbfbfdd80) Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: Sending PPPOE_CONNECT to .:tun0 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: timer_Start: Inserting physical throughput timer[0x80bb068] Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: deflink: Connected! Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: deflink: opening -> dial Dec 11 17:25:02 fw ppp[52460]: tun0: Chat: deflink: Dial attempt 1 of 1 Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: deflink: dial -> carrier Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: m_enqueue: len = 14 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: m_enqueue: len = 15 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: m_enqueue: len = 16 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: m_enqueue: len = 17 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: m_enqueue: len = 18 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: deflink: Disconnected! Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: deflink: carrier -> hangup Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: deflink: Close Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: deflink: Connect time: 0 secs: 0 octets in, 0 octets out Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: deflink: 5159567 packets in, 4539264 packets out Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: total 0 bytes/sec, peak 0 bytes/sec on Tue Dec 11 17:25:02 2007 Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: deflink: hangup -> closed Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: bundle: Dead Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: timer_Start: Inserting dial timer[0x80b9d44] Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: bundle: Establish Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: deflink: closed -> opening Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: m_enqueue: len = 19 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:25:02 fw ppp[52460]: tun0: ID0: 0 = NgMkSockNode("", &cs, &ds) Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: List of netgraph node ``sis0:'' (id 1) hooks: Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: Found orphans -> ethernet Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: Connecting netgraph socket .:tun0 -> [5]::tun0 Dec 11 17:25:02 fw ppp[52460]: tun0: ID0: 3 = socket(2, 2, 0) Dec 11 17:25:02 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 3223349521, 0xbfbfdd80) Dec 11 17:25:02 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 2149607696, 0xbfbfdd80) Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: Sending PPPOE_CONNECT to .:tun0 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: timer_Start: Inserting physical throughput timer[0x80bb068] Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: deflink: Connected! Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: deflink: opening -> dial Dec 11 17:25:02 fw ppp[52460]: tun0: Chat: deflink: Dial attempt 1 of 1 Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: deflink: dial -> carrier Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: m_enqueue: len = 20 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: m_enqueue: len = 21 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: m_enqueue: len = 22 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: m_enqueue: len = 23 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: m_enqueue: len = 24 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: deflink: Disconnected! Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: deflink: carrier -> hangup Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: deflink: Close Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: deflink: Connect time: 0 secs: 0 octets in, 0 octets out Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: deflink: 5159567 packets in, 4539264 packets out Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: total 0 bytes/sec, peak 0 bytes/sec on Tue Dec 11 17:25:02 2007 Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: deflink: hangup -> closed Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: bundle: Dead Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: timer_Start: Inserting dial timer[0x80b9d44] Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: bundle: Establish Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: deflink: closed -> opening Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: m_enqueue: len = 25 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:25:02 fw ppp[52460]: tun0: ID0: 0 = NgMkSockNode("", &cs, &ds) Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: List of netgraph node ``sis0:'' (id 1) hooks: Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: Found orphans -> ethernet Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: Connecting netgraph socket .:tun0 -> [5]::tun0 Dec 11 17:25:02 fw ppp[52460]: tun0: ID0: 3 = socket(2, 2, 0) Dec 11 17:25:02 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 3223349521, 0xbfbfdd80) Dec 11 17:25:02 fw ppp[52460]: tun0: ID0: 0 = ioctl(3, 2149607696, 0xbfbfdd80) Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: Sending PPPOE_CONNECT to .:tun0 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: timer_Start: Inserting physical throughput timer[0x80bb068] Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: deflink: Connected! Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: deflink: opening -> dial Dec 11 17:25:02 fw ppp[52460]: tun0: Chat: deflink: Dial attempt 1 of 1 Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: deflink: dial -> carrier Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: m_enqueue: len = 26 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: m_enqueue: len = 27 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: m_enqueue: len = 28 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: m_enqueue: len = 29 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: tun: fdset(r) 6 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: Waiting for carrier Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: m_enqueue: len = 30 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: timer_Start: Inserting output choke timer[0x80ad520] Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: deflink: Disconnected! Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: deflink: carrier -> hangup Dec 11 17:25:02 fw ppp[52460]: tun0: Debug: deflink: Close Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: deflink: Connect time: 0 secs: 0 octets in, 0 octets out Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: deflink: 5159567 packets in, 4539264 packets out Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: total 0 bytes/sec, peak 0 bytes/sec on Tue Dec 11 17:25:02 2007 Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: deflink: hangup -> closed Dec 11 17:25:02 fw ppp[52460]: tun0: Phase: bundle: Dead Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: timer_Start: Inserting dial timer[0x80b9d44] before output choke timer[0x80ad520], delta = 300 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:25:02 fw ppp[52460]: tun0: Timer: prompt /var/run/internet: fdset(r) 2 Dec 11 17:25:24 fw ppp[52460]: tun0: Timer: Select returns 1 Dec 11 17:25:24 fw ppp[52460]: tun0: Command: /var/run/internet: quit Dec 11 17:25:24 fw ppp[52460]: tun0: Phase: /var/run/internet: Client connection dropped. Dec 11 17:25:24 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:25:32 fw ppp[52460]: tun0: Timer: Select returns -1 Dec 11 17:25:32 fw ppp[52460]: tun0: Timer: ---- Begin of Timer Service List--- Dec 11 17:25:32 fw ppp[52460]: tun0: Timer: dial timer[0x80b9d44]: freq = 30.00s, next = 0.00s, state = running Dec 11 17:25:32 fw ppp[52460]: tun0: Timer: output choke timer[0x80ad520]: freq = 120.00s, next = 90.00s, state = running Dec 11 17:25:32 fw ppp[52460]: tun0: Timer: ---- End of Timer Service List --- Dec 11 17:25:32 fw ppp[52460]: tun0: Timer: server: fdset(r) 9 Dec 11 17:25:58 fw ppp[52460]: tun0: Timer: Select returns -1 Dec 11 17:25:58 fw ppp[52460]: tun0: Phase: Signal 15, terminate. Dec 11 17:25:58 fw ppp[52460]: tun0: Debug: DoLoop done. Dec 11 17:25:58 fw ppp[52460]: tun0: Phase: PPP Terminated (normal). Dec 11 17:25:58 fw ppp[52460]: tun0: ID0: 0 = socket(2, 2, 0) Dec 11 17:25:58 fw ppp[52460]: tun0: ID0: 0 = ioctl(0, 2149607705, 0xbfbfe600) Dec 11 17:25:58 fw ppp[52460]: tun0: Warning: tun0: DIFADDR WWW.XXX.YYY.ZZZ -> GGG.HHH.III.JJJ returns 0 Dec 11 17:25:58 fw ppp[52460]: tun0: Debug: route_IfDelete (6) Dec 11 17:25:58 fw ppp[52460]: tun0: Debug: Found ff01:6::/32 Dec 11 17:25:58 fw ppp[52460]: tun0: Debug: route_IfDelete: Skip it (pass 0) Dec 11 17:25:58 fw ppp[52460]: tun0: Debug: Found ff02:6::/32 Dec 11 17:25:58 fw ppp[52460]: tun0: Debug: route_IfDelete: Skip it (pass 0) Dec 11 17:25:58 fw ppp[52460]: tun0: Debug: Found ff01:6::/32 Dec 11 17:25:58 fw ppp[52460]: tun0: ID0: 1 = socket(17, 3, 0) Dec 11 17:25:58 fw ppp[52460]: tun0: ID0: 148 = write(1, data, 148) Dec 11 17:25:58 fw ppp[52460]: tun0: Debug: wrote 148: cmd = Delete, dst = ff01:6::/32, gateway = Dec 11 17:25:58 fw ppp[52460]: tun0: Debug: Found ff02:6::/32 Dec 11 17:25:58 fw ppp[52460]: tun0: ID0: 1 = socket(17, 3, 0) Dec 11 17:25:58 fw ppp[52460]: tun0: ID0: 148 = write(1, data, 148) Dec 11 17:25:58 fw ppp[52460]: tun0: Debug: wrote 148: cmd = Delete, dst = ff02:6::/32, gateway = Dec 11 17:25:58 fw ppp[52460]: tun0: ID0: 1 = socket(2, 2, 0) Dec 11 17:25:58 fw ppp[52460]: tun0: ID0: 0 = ioctl(1, 3223349521, 0xbfbfe660) Dec 11 17:25:58 fw ppp[52460]: tun0: ID0: 0 = ioctl(1, 2149607696, 0xbfbfe660) Dec 11 17:25:58 fw ppp[52460]: tun0: Debug: Radius: radius_Destroy Dec 11 17:25:58 fw ppp[52460]: tun0: ID0: 0 = unlink("/var/run/tun0.pid") -------------------- manually restarted ppp ------------------------------ Dec 11 17:26:17 fw ppp[64071]: Phase: Using interface: tun0 Dec 11 17:26:17 fw ppp[64071]: Phase: deflink: Created in closed state Dec 11 17:26:17 fw ppp[64071]: tun0: Command: default: ident user-ppp VERSION (built COMPILATIONDATE) Dec 11 17:26:17 fw ppp[64071]: tun0: ID0: 0x282fe180 = fopen("/etc/ppp/ppp.conf", "r") Dec 11 17:26:17 fw ppp[64071]: tun0: Debug: ReadSystem: Checking sling2 (/etc/ppp/ppp.conf). Dec 11 17:26:17 fw ppp[64071]: tun0: Command: sling2: set device PPPoE:sis0 Dec 11 17:26:17 fw ppp[64071]: tun0: Command: sling2: set MTU 1460 Dec 11 17:26:17 fw ppp[64071]: tun0: Command: sling2: set MRU 1460 Dec 11 17:26:17 fw ppp[64071]: tun0: Command: sling2: set dial Dec 11 17:26:17 fw ppp[64071]: tun0: Command: sling2: set crtscts off Dec 11 17:26:17 fw ppp[64071]: tun0: Command: sling2: set speed sync Dec 11 17:26:17 fw ppp[64071]: tun0: Command: sling2: disable lqr Dec 11 17:26:17 fw ppp[64071]: tun0: Command: sling2: set echoperiod 30 Dec 11 17:26:17 fw ppp[64071]: tun0: Command: sling2: enable echo Dec 11 17:26:17 fw ppp[64071]: tun0: Command: sling2: disable deflate Dec 11 17:26:17 fw ppp[64071]: tun0: Command: sling2: disable pred1 Dec 11 17:26:17 fw ppp[64071]: tun0: Command: sling2: disable vjcomp Dec 11 17:26:17 fw ppp[64071]: tun0: Command: sling2: disable acfcomp Dec 11 17:26:17 fw ppp[64071]: tun0: Command: sling2: disable protocomp Dec 11 17:26:17 fw ppp[64071]: tun0: Command: sling2: set log Phase LCP IPCP CCP Warning Error Alert Dec 11 17:26:17 fw ppp[64071]: Phase: Listening at local socket /var/run/internet. Dec 11 17:26:17 fw ppp[64072]: Phase: PPP Started (auto mode). Dec 11 17:26:17 fw ppp[64072]: Phase: bundle: Establish Dec 11 17:26:17 fw ppp[64072]: Phase: deflink: closed -> opening Dec 11 17:26:17 fw ppp[64072]: Phase: deflink: Connected! Dec 11 17:26:17 fw ppp[64072]: Phase: deflink: opening -> dial Dec 11 17:26:17 fw ppp[64072]: Phase: deflink: dial -> carrier Dec 11 17:26:19 fw ppp[64072]: Phase: Received NGM_PPPOE_ACNAME (hook "DSSX43-erx") Dec 11 17:26:19 fw ppp[64072]: Phase: Received NGM_PPPOE_SESSIONID Dec 11 17:26:19 fw ppp[64072]: Phase: Received NGM_PPPOE_SUCCESS Dec 11 17:26:19 fw ppp[64072]: Phase: deflink: carrier -> login Dec 11 17:26:19 fw ppp[64072]: Phase: deflink: login -> lcp Dec 11 17:26:19 fw ppp[64072]: LCP: FSM: Using "deflink" as a transport Dec 11 17:26:19 fw ppp[64072]: LCP: deflink: State change Initial --> Closed Dec 11 17:26:19 fw ppp[64072]: LCP: deflink: State change Closed --> Stopped Dec 11 17:26:20 fw ppp[64072]: LCP: deflink: LayerStart Dec 11 17:26:20 fw ppp[64072]: LCP: deflink: SendConfigReq(1) state = Stopped Dec 11 17:26:20 fw ppp[64072]: LCP: MRU[4] 1460 Dec 11 17:26:20 fw ppp[64072]: LCP: MAGICNUM[6] 0xc3ce3752 Dec 11 17:26:20 fw ppp[64072]: LCP: deflink: State change Stopped --> Req-Sent Dec 11 17:26:21 fw ppp[64072]: LCP: deflink: RecvConfigReq(248) state = Req-Sent Dec 11 17:26:21 fw ppp[64072]: LCP: MRU[4] 1492 Dec 11 17:26:21 fw ppp[64072]: LCP: AUTHPROTO[4] 0xc023 (PAP) Dec 11 17:26:21 fw ppp[64072]: LCP: MAGICNUM[6] 0x6e9fdc91 Dec 11 17:26:21 fw ppp[64072]: LCP: deflink: SendConfigAck(248) state = Req-Sent Dec 11 17:26:21 fw ppp[64072]: LCP: MRU[4] 1492 Dec 11 17:26:21 fw ppp[64072]: LCP: AUTHPROTO[4] 0xc023 (PAP) Dec 11 17:26:21 fw ppp[64072]: LCP: MAGICNUM[6] 0x6e9fdc91 Dec 11 17:26:21 fw ppp[64072]: LCP: deflink: State change Req-Sent --> Ack-Sent Dec 11 17:26:21 fw ppp[64072]: LCP: deflink: RecvConfigAck(1) state = Ack-Sent Dec 11 17:26:21 fw ppp[64072]: LCP: MRU[4] 1460 Dec 11 17:26:21 fw ppp[64072]: LCP: MAGICNUM[6] 0xc3ce3752 Dec 11 17:26:21 fw ppp[64072]: LCP: deflink: State change Ack-Sent --> Opened Dec 11 17:26:21 fw ppp[64072]: LCP: deflink: LayerUp Dec 11 17:26:21 fw ppp[64072]: LCP: deflink: SendEchoRequest(0) state = Opened Dec 11 17:26:21 fw ppp[64072]: LCP: deflink: SendIdent(0) state = Opened Dec 11 17:26:21 fw ppp[64072]: LCP: MAGICNUM c3ce3752 Dec 11 17:26:21 fw ppp[64072]: LCP: TEXT user-ppp 3.4.2 (built Nov 30 2007) Dec 11 17:26:21 fw ppp[64072]: Phase: bundle: Authenticate Dec 11 17:26:21 fw ppp[64072]: Phase: deflink: his = PAP, mine = none Dec 11 17:26:21 fw ppp[64072]: Phase: Pap Output: XXXXXXXXXXXXXXXXXXXXXXXXXXX ******** Dec 11 17:26:21 fw ppp[64072]: LCP: deflink: RecvEchoReply(0) state = Opened Dec 11 17:26:21 fw ppp[64072]: LCP: deflink: RecvConfigReq(1) state = Opened Dec 11 17:26:21 fw ppp[64072]: LCP: deflink: LayerDown Dec 11 17:26:21 fw ppp[64072]: LCP: MRU[4] 1492 Dec 11 17:26:21 fw ppp[64072]: LCP: AUTHPROTO[4] 0xc023 (PAP) Dec 11 17:26:21 fw ppp[64072]: LCP: MAGICNUM[6] 0x1151bf46 Dec 11 17:26:21 fw ppp[64072]: LCP: deflink: SendConfigReq(2) state = Opened Dec 11 17:26:21 fw ppp[64072]: LCP: MRU[4] 1460 Dec 11 17:26:21 fw ppp[64072]: LCP: MAGICNUM[6] 0xe7d2d603 Dec 11 17:26:21 fw ppp[64072]: LCP: deflink: SendConfigAck(1) state = Opened Dec 11 17:26:21 fw ppp[64072]: LCP: MRU[4] 1492 Dec 11 17:26:21 fw ppp[64072]: LCP: AUTHPROTO[4] 0xc023 (PAP) Dec 11 17:26:21 fw ppp[64072]: LCP: MAGICNUM[6] 0x1151bf46 Dec 11 17:26:21 fw ppp[64072]: LCP: deflink: State change Opened --> Ack-Sent Dec 11 17:26:21 fw ppp[64072]: LCP: deflink: RecvConfigNak(2) state = Ack-Sent Dec 11 17:26:21 fw ppp[64072]: LCP: MRU[4] 1492 Dec 11 17:26:21 fw ppp[64072]: LCP: deflink: SendConfigReq(3) state = Ack-Sent Dec 11 17:26:21 fw ppp[64072]: LCP: MRU[4] 1460 Dec 11 17:26:21 fw ppp[64072]: LCP: MAGICNUM[6] 0xe7d2d603 Dec 11 17:26:21 fw ppp[64072]: LCP: deflink: RecvConfigNak(3) state = Ack-Sent Dec 11 17:26:21 fw ppp[64072]: LCP: MRU[4] 1492 Dec 11 17:26:21 fw ppp[64072]: LCP: deflink: SendConfigReq(4) state = Ack-Sent Dec 11 17:26:21 fw ppp[64072]: LCP: MRU[4] 1460 Dec 11 17:26:21 fw ppp[64072]: LCP: MAGICNUM[6] 0xe7d2d603 Dec 11 17:26:21 fw ppp[64072]: LCP: deflink: RecvConfigNak(4) state = Ack-Sent Dec 11 17:26:21 fw ppp[64072]: LCP: MRU[4] 1492 Dec 11 17:26:21 fw ppp[64072]: LCP: deflink: SendConfigReq(5) state = Ack-Sent Dec 11 17:26:21 fw ppp[64072]: LCP: MRU[4] 1460 Dec 11 17:26:21 fw ppp[64072]: LCP: MAGICNUM[6] 0xe7d2d603 Dec 11 17:26:21 fw ppp[64072]: LCP: deflink: RecvConfigNak(5) state = Ack-Sent Dec 11 17:26:21 fw ppp[64072]: LCP: MRU[4] 1492 Dec 11 17:26:21 fw ppp[64072]: LCP: deflink: SendConfigReq(6) state = Ack-Sent Dec 11 17:26:21 fw ppp[64072]: LCP: MRU[4] 1460 Dec 11 17:26:21 fw ppp[64072]: LCP: MAGICNUM[6] 0xe7d2d603 Dec 11 17:26:21 fw ppp[64072]: LCP: deflink: RecvConfigNak(6) state = Ack-Sent Dec 11 17:26:21 fw ppp[64072]: LCP: MRU[4] 1492 Dec 11 17:26:21 fw ppp[64072]: LCP: deflink: SendConfigReq(7) state = Ack-Sent Dec 11 17:26:21 fw ppp[64072]: LCP: MRU[4] 1460 Dec 11 17:26:21 fw ppp[64072]: LCP: MAGICNUM[6] 0xe7d2d603 Dec 11 17:26:21 fw ppp[64072]: LCP: deflink: RecvConfigRej(7) state = Ack-Sent Dec 11 17:26:21 fw ppp[64072]: LCP: deflink: SendIdent(1) state = Ack-Sent Dec 11 17:26:21 fw ppp[64072]: LCP: MAGICNUM e7d2d603 Dec 11 17:26:21 fw ppp[64072]: LCP: TEXT user-ppp 3.4.2 (built Nov 30 2007) Dec 11 17:26:21 fw ppp[64072]: LCP: MRU[4] 1460 Dec 11 17:26:21 fw ppp[64072]: LCP: deflink: SendConfigReq(8) state = Ack-Sent Dec 11 17:26:21 fw ppp[64072]: LCP: MAGICNUM[6] 0xe7d2d603 Dec 11 17:26:21 fw ppp[64072]: LCP: deflink: RecvConfigAck(8) state = Ack-Sent Dec 11 17:26:21 fw ppp[64072]: LCP: MAGICNUM[6] 0xe7d2d603 Dec 11 17:26:21 fw ppp[64072]: LCP: deflink: State change Ack-Sent --> Opened Dec 11 17:26:21 fw ppp[64072]: LCP: deflink: LayerUp Dec 11 17:26:21 fw ppp[64072]: LCP: deflink: SendEchoRequest(0) state = Opened Dec 11 17:26:21 fw ppp[64072]: LCP: deflink: SendIdent(2) state = Opened Dec 11 17:26:21 fw ppp[64072]: LCP: MAGICNUM e7d2d603 Dec 11 17:26:21 fw ppp[64072]: LCP: TEXT user-ppp 3.4.2 (built Nov 30 2007) Dec 11 17:26:21 fw ppp[64072]: Phase: deflink: his = PAP, mine = none Dec 11 17:26:21 fw ppp[64072]: Phase: Pap Output: XXXXXXXXXXXXXXXXXXXXXXXXXXX ******** Dec 11 17:26:21 fw ppp[64072]: LCP: deflink: RecvEchoReply(0) state = Opened Dec 11 17:26:22 fw ppp[64072]: LCP: deflink: RecvConfigReq(1) state = Opened Dec 11 17:26:22 fw ppp[64072]: LCP: deflink: LayerDown Dec 11 17:26:22 fw ppp[64072]: LCP: MRU[4] 1460 Dec 11 17:26:22 fw ppp[64072]: LCP: AUTHPROTO[4] 0xc023 (PAP) Dec 11 17:26:22 fw ppp[64072]: LCP: MAGICNUM[6] 0xff1c30dc Dec 11 17:26:22 fw ppp[64072]: LCP: deflink: SendConfigReq(9) state = Opened Dec 11 17:26:22 fw ppp[64072]: LCP: MRU[4] 1460 Dec 11 17:26:22 fw ppp[64072]: LCP: MAGICNUM[6] 0x363320d5 Dec 11 17:26:22 fw ppp[64072]: LCP: deflink: SendConfigAck(1) state = Opened Dec 11 17:26:22 fw ppp[64072]: LCP: MRU[4] 1460 Dec 11 17:26:22 fw ppp[64072]: LCP: AUTHPROTO[4] 0xc023 (PAP) Dec 11 17:26:22 fw ppp[64072]: LCP: MAGICNUM[6] 0xff1c30dc Dec 11 17:26:22 fw ppp[64072]: LCP: deflink: State change Opened --> Ack-Sent Dec 11 17:26:22 fw ppp[64072]: LCP: deflink: RecvConfigAck(9) state = Ack-Sent Dec 11 17:26:22 fw ppp[64072]: LCP: MRU[4] 1460 Dec 11 17:26:22 fw ppp[64072]: LCP: MAGICNUM[6] 0x363320d5 Dec 11 17:26:22 fw ppp[64072]: LCP: deflink: State change Ack-Sent --> Opened Dec 11 17:26:22 fw ppp[64072]: LCP: deflink: LayerUp Dec 11 17:26:22 fw ppp[64072]: LCP: deflink: SendEchoRequest(0) state = Opened Dec 11 17:26:22 fw ppp[64072]: LCP: deflink: SendIdent(3) state = Opened Dec 11 17:26:22 fw ppp[64072]: LCP: MAGICNUM 363320d5 Dec 11 17:26:22 fw ppp[64072]: LCP: TEXT user-ppp 3.4.2 (built Nov 30 2007) Dec 11 17:26:22 fw ppp[64072]: Phase: deflink: his = PAP, mine = none Dec 11 17:26:22 fw ppp[64072]: Phase: Pap Output: XXXXXXXXXXXXXXXXXXXXXXXXXXX ******** Dec 11 17:26:22 fw ppp[64072]: LCP: deflink: RecvEchoReply(0) state = Opened Dec 11 17:26:22 fw ppp[64072]: Phase: Pap Input: SUCCESS () Dec 11 17:26:22 fw ppp[64072]: IPCP: Using trigger address 0.0.0.0 Dec 11 17:26:22 fw ppp[64072]: CCP: FSM: Using "deflink" as a transport Dec 11 17:26:22 fw ppp[64072]: CCP: deflink: State change Initial --> Closed Dec 11 17:26:22 fw ppp[64072]: CCP: deflink: LayerStart. Dec 11 17:26:22 fw ppp[64072]: CCP: MPPE: Not usable without CHAP81 Dec 11 17:26:22 fw ppp[64072]: CCP: deflink: SendConfigReq(1) state = Closed Dec 11 17:26:22 fw ppp[64072]: CCP: [EMPTY] Dec 11 17:26:22 fw ppp[64072]: CCP: deflink: State change Closed --> Req-Sent Dec 11 17:26:22 fw ppp[64072]: Phase: deflink: lcp -> open Dec 11 17:26:22 fw ppp[64072]: Phase: bundle: Network Dec 11 17:26:22 fw ppp[64072]: IPCP: FSM: Using "deflink" as a transport Dec 11 17:26:22 fw ppp[64072]: IPCP: deflink: State change Initial --> Closed Dec 11 17:26:22 fw ppp[64072]: IPCP: deflink: LayerStart. Dec 11 17:26:22 fw ppp[64072]: IPCP: deflink: SendConfigReq(1) state = Closed Dec 11 17:26:22 fw ppp[64072]: IPCP: IPADDR[6] 0.0.0.0 Dec 11 17:26:22 fw ppp[64072]: IPCP: deflink: State change Closed --> Req-Sent Dec 11 17:26:22 fw ppp[64072]: IPCP: deflink: RecvConfigReq(1) state = Req-Sent Dec 11 17:26:22 fw ppp[64072]: IPCP: IPADDR[6] GGG.HHH.III.JJJ Dec 11 17:26:22 fw ppp[64072]: IPCP: deflink: SendConfigAck(1) state = Req-Sent Dec 11 17:26:22 fw ppp[64072]: IPCP: IPADDR[6] GGG.HHH.III.JJJ Dec 11 17:26:22 fw ppp[64072]: IPCP: deflink: State change Req-Sent --> Ack-Sent Dec 11 17:26:22 fw ppp[64072]: LCP: deflink: RecvProtocolRej(2) state = Opened Dec 11 17:26:22 fw ppp[64072]: LCP: deflink: -- Protocol 0x80fd (Compression Control Protocol) was rejected! Dec 11 17:26:22 fw ppp[64072]: CCP: deflink: State change Req-Sent --> Stopped Dec 11 17:26:22 fw ppp[64072]: IPCP: deflink: RecvConfigNak(1) state = Ack-Sent Dec 11 17:26:22 fw ppp[64072]: IPCP: IPADDR[6] WWW.XXX.YYY.ZZZ Dec 11 17:26:22 fw ppp[64072]: IPCP: IPADDR[6] changing address: 0.0.0.0 --> WWW.XXX.YYY.ZZZ Dec 11 17:26:22 fw ppp[64072]: IPCP: deflink: SendConfigReq(2) state = Ack-Sent Dec 11 17:26:22 fw ppp[64072]: IPCP: IPADDR[6] WWW.XXX.YYY.ZZZ Dec 11 17:26:22 fw ppp[64072]: LCP: deflink: RecvProtocolRej(3) state = Opened Dec 11 17:26:22 fw ppp[64072]: LCP: deflink: -- Protocol 0x8057 (Internet Protocol V6 Control Protocol) was rejected! Dec 11 17:26:22 fw ppp[64072]: Phase: deflink: IPV6CP protocol reject closes IPV6CP ! Dec 11 17:26:22 fw ppp[64072]: IPCP: deflink: RecvConfigAck(2) state = Ack-Sent Dec 11 17:26:22 fw ppp[64072]: IPCP: IPADDR[6] WWW.XXX.YYY.ZZZ Dec 11 17:26:22 fw ppp[64072]: IPCP: deflink: State change Ack-Sent --> Opened Dec 11 17:26:22 fw ppp[64072]: IPCP: deflink: LayerUp. Dec 11 17:26:22 fw ppp[64072]: IPCP: myaddr WWW.XXX.YYY.ZZZ hisaddr = GGG.HHH.III.JJJ Dec 11 17:26:22 fw ppp[64072]: Warning: 0.0.0.0/0: Change route failed: errno: No such process Dec 11 17:26:23 fw ppp[64072]: LCP: deflink: RecvEchoRequest(1) state = Opened Dec 11 17:26:23 fw ppp[64072]: LCP: deflink: SendEchoReply(1) state = Opened Dec 11 17:26:30 fw ppp[64072]: Phase: Connected to local client. Dec 11 17:26:33 fw ppp[64072]: LCP: deflink: RecvEchoRequest(2) state = Opened Dec 11 17:26:33 fw ppp[64072]: LCP: deflink: SendEchoReply(2) state = Opened Dec 11 17:27:14 fw ppp[64072]: tun0: LCP: deflink: RecvEchoRequest(6) state = Opened Dec 11 17:27:14 fw ppp[64072]: tun0: LCP: deflink: SendEchoReply(6) state = Opened Dec 11 17:27:23 fw ppp[64072]: tun0: LCP: deflink: SendEchoRequest(2) state = Opened Dec 11 17:27:23 fw ppp[64072]: tun0: LCP: deflink: RecvEchoReply(2) state = Opened Dec 11 17:27:24 fw ppp[64072]: tun0: LCP: deflink: RecvEchoRequest(7) state = Opened Dec 11 17:27:24 fw ppp[64072]: tun0: LCP: deflink: SendEchoReply(7) state = Opened Dec 11 17:27:34 fw ppp[64072]: tun0: LCP: deflink: RecvEchoRequest(8) state = Opened Dec 11 17:27:34 fw ppp[64072]: tun0: LCP: deflink: SendEchoReply(8) state = Opened Dec 11 17:27:45 fw ppp[64072]: tun0: LCP: deflink: RecvEchoRequest(9) state = Opened Dec 11 17:27:45 fw ppp[64072]: tun0: LCP: deflink: SendEchoReply(9) state = Opened Dec 11 17:27:53 fw ppp[64072]: tun0: LCP: deflink: SendEchoRequest(3) state = Opened Dec 11 17:27:54 fw ppp[64072]: tun0: LCP: deflink: RecvEchoReply(3) state = Opened Dec 11 17:27:55 fw ppp[64072]: tun0: LCP: deflink: RecvEchoRequest(10) state = Opened Dec 11 17:27:55 fw ppp[64072]: tun0: LCP: deflink: SendEchoReply(10) state = Opened Dec 11 17:28:00 fw ppp[64072]: tun0: Command: /var/run/internet: quit Dec 11 17:28:00 fw ppp[64072]: tun0: Phase: /var/run/internet: Client connection dropped. Dec 11 17:28:05 fw ppp[64072]: tun0: LCP: deflink: RecvEchoRequest(11) state = Opened Dec 11 17:28:05 fw ppp[64072]: tun0: LCP: deflink: SendEchoReply(11) state = Opened Dec 11 17:28:15 fw ppp[64072]: tun0: LCP: deflink: RecvEchoRequest(12) state = Opened Dec 11 17:28:15 fw ppp[64072]: tun0: LCP: deflink: SendEchoReply(12) state = Opened Dec 11 17:28:24 fw ppp[64072]: tun0: LCP: deflink: SendEchoRequest(4) state = Opened Dec 11 17:28:24 fw ppp[64072]: tun0: LCP: deflink: RecvEchoReply(4) state = Opened