[Snap] Snap ADSL authentication problem.

Forums › 2degrees (including Slingshot, Orcon, Flip, Stuff Fibre, MyRepublic, 2talk and Vocus) › [Snap] Snap ADSL authentication problem.

jdmatt

28 posts

Geek

#144043 5-May-2014 19:19

Hi all, long time lurker first time poster here on geekzone. Love this place, has a lot of helpful information. Now can you help me. I have recently switched from TelecomNZ to Snap and have been having trouble with authentication problems where I lose connectivity but my DSL sync remains and I have to reset my modem every time to regain my connection.

I have tried with 2 different modems and the problem is persistent on both routers. Both routers had got a factory reset then programmed with Snaps ADSL settings to make sure there is no conflict with old telecom settings.

I have contacted snap support by email and have given them a screenshot of my PPP settings and a copy of the syslog. They replied back and said "everything appears to be set correctly in the modem have you tried a different modem?". I replied and said yes, but have not received a reply.

Below is a copy of my syslog when I lose my connection.

May 03 23:54:59 daemon pppd[1899]: PPP: Start to connect ...
May 03 23:54:59 daemon pppd[1899]: Using interface ppp0_0_100_1
May 03 23:54:59 daemon pppd[1899]: Connect: ppp_0_0_100_1 <-->
May 03 23:55:00 daemon dhcp6c[1561]: client6_send: transmit failed: Network is unreachable
May 03 23:55:08 daemon pppd[1899]: LCP: timeout sending Config-Requests
May 03 23:55:08 daemon pppd[1899]: Connection terminated.
May 03 23:55:11 daemon pppd[1899]: PPP: Start to connect ...
May 03 23:55:11 daemon pppd[1899]: Using interface ppp0_0_100_1
May 03 23:55:11 daemon pppd[1899]: Connect: ppp_0_0_100_1 <-->
May 03 23:55:20 daemon pppd[1899]: LCP: timeout sending Config-Requests
May 03 23:55:20 daemon pppd[1899]: Connection terminated.

Both routers, a Billion 7800n & Netgear dg834g previosly work perfectly on the telecom network.

Could these drops out be caused from a conflict with telecom of some sort, maybe some problems at the dslam? I have no idea about this sort of stuff but the drops are frustrating, your help is appreciated. Thanks

1 | 2

6019 posts

Uber Geek

Trusted

Geekzone

Lifetime subscriber

#1037260 5-May-2014 19:19

Hello... Our robot found some keywords in your post, so here is an automated reply with some important things to note regarding broadband speeds.

If you are posting regarding DSL speeds please check that

- you have reset your modem and router

- your PC (or other PCs in your LAN) is not downloading large files when you are testing

- you are not being throttled by your ISP due to going over the monthly cap

- your tests are always done on an ethernet connection to the router - do not use wireless for testing

- you read this topic and follow the instructions there.

Make sure you provide information for other users to help you. If you have not already done it, please EDIT your post and add this now:

- Your ISP and plan

- Type of connection (ADSL, ADSL2, VDSL)

- Your modem DSL stats (do not worry about posting Speedtest, we need sync rate, attenuation and noise margin)

- Your general location (or street)

- If you are rural or urban

- If you know your connection is to an exchange, cabinet or conklin

- If your connection is to a ULL or wholesale service

- If you have done an isolation test as per the link above

Most of the problems with speed are likely to be related to internal wiring issues. Read this discussion to find out more about this. Your ISP is not intentionally slowing you down today (unless you are on a managed plan). Also if this is the school holidays it's likely you will notice slower than usual speed due to more users online.

A master splitter is required for VDSL2 and in most cases will improve speeds on DSL connections. Regular disconnections can be a monitored alarm or a set top box trying to connect. If there's an alarm connected to your line even if you don't have an alarm contract it may still try to connect so it's worth checking.

I recommend you read these two blog posts:

- Is your premises phone wiring impacting your broadband performance? (very technical)

- Are you receiving a substandard ULL ADSL2+ connection from your ISP?

I am the Geekzone Robot and I am here to help. I am from the Internet. I do not interact. Do not expect other replies from me.

nzgeek

618 posts

Ultimate Geek

#1037337 5-May-2014 20:59

What exactly do you mean by "lose connectivity?" Does that mean that it'll connect and work for a while, and then randomly drop out?

I only ask because the log snippet you posted tends to indicate that you're not connecting properly at all. The LCP thing (link control protocol) that's timing out it's part of the PPP negotiation process. It looks like maybe the link between the DSLAM and Snap hasn't been configured correctly.

Snap should be able to run some connectivity tests to figure this one out. Your best bet is to call while it's happening so they can see what's going on from their end. They should be able to get enough info to sort you out.

jdmatt

28 posts

Geek

#1037648 6-May-2014 11:34

nzgeek: What exactly do you mean by "lose connectivity?" Does that mean that it'll connect and work for a while, and then randomly drop out?

Sorry I should have explain better, but yes it will connect for a while 6 -12hrs then it drops out and then tries to reconnect but cannot unless I restart the modem. I will call snap when I get a chance to and see how I go with them.

This is the syslog from moments ago when I restarted the router. Will try and get a copy of the syslog when it drops the connection again.

Jan 01 00:00:11 user kernel: Config Internal PHY Through MDIO
Jan 01 00:00:11 user kernel: ENET: Auto-negotiation timed-out
Jan 01 00:00:11 user kernel: ENET: 10 MB Half-Duplex (assumed)
Jan 01 00:00:11 user kernel: eth0: MAC Address: 00:04:ED:EC:53:D7
Jan 01 00:00:11 user kernel: Config Ethernet Switch Through MDIO Pseudo PHY Interface
Jan 01 00:00:11 user kernel: ethsw: found bcm5395!
Jan 01 00:00:11 user kernel: dgasp: kerSysRegisterDyingGaspHandler: eth1 registered
Jan 01 00:00:11 user kernel: eth1: MAC Address: 00:04:ED:EC:53:D7
Jan 01 00:00:11 user kernel: eth1 Link UP.
Jan 01 00:00:11 user kernel: rt2880_iNIC: falsely claims to have parameter csumoff
Jan 01 00:00:11 user kernel: RT2880iNIC: 802.11n WLAN PCI driver v2.5.1.0 (Feb. 2, 2012)
Jan 01 00:00:11 user kernel: RT2880iNIC: pci dev 0000:00:01.0 (id 1814:0801 rev 00)
Jan 01 00:00:11 user kernel: PCI: Enabling device 0000:00:01.0 (0000 -> 0002)
Jan 01 00:00:11 user kernel: rt->regs = b0100000
Jan 01 00:00:11 user kernel: Update MAC(0)=00:04:ed:e8:40:a0
Jan 01 00:00:11 user kernel: ============= Init Thread ===================
Jan 01 00:00:11 user kernel: RacfgTaskThread pid = 74
Jan 01 00:00:11 user kernel: RacfgBacklogThread pid = 75
Jan 01 00:00:11 user kernel: ra0: Ralink iNIC at 0xb0100000, 00:04:ed:e8:40:a0, IRQ 39
Jan 01 00:00:11 user kernel: PCI: Setting latency timer of device 0000:00:01.0 to 64
Jan 01 00:00:11 daemon dnsmasq[91]: using nameserver 8.8.4.4#53
Jan 01 00:00:11 daemon dnsmasq[91]: using nameserver 8.8.8.8#53
Jan 01 00:00:11 user kernel: BcmAdsl_Initialize=0xC006F7D8, g_pFnNotifyCallback=0xC0091A04
Jan 01 00:00:11 user kernel: pSdramPHY=0xA1FFFFF8, 0x1B7812 0xDEADBEEF
Jan 01 00:00:12 user kernel: AdslCoreSharedMemInit: shareMemAvailable=19296
Jan 01 00:00:12 user kernel: AdslCoreHwReset: AdslOemDataAddr = 0xA1FF02DC
Jan 01 00:00:12 user kernel: dgasp: kerSysRegisterDyingGaspHandler: dsl0 registered
Jan 01 00:00:12 user kernel: ATM proc init !!!
Jan 01 00:00:12 user kernel: KLOB extended to 2 pools
Jan 01 00:00:14 user kernel: BRCM NAT Caching v0.1 Jul 3 2007 10:16:19
Jan 01 00:00:14 user kernel: BRCM NAT Cache: Hooking hit function @ c006cc48
Jan 01 00:00:17 user kernel: ip6_tables: (C) 2000-2002 Netfilter core team
Jan 01 00:00:18 user kernel: ip6_conntrack version 0.1 (253 buckets, 2024 max) - 208 bytes per conntrack
Jan 01 00:00:19 user kernel: Line 0: xDSL G.994 training
Jan 01 00:00:20 user syslog: ifconfig eth0 up
Jan 01 00:00:20 user syslog: ifconfig br0 192.168.1.254 netmask 255.255.255.0 broadcast 192.168.1.255 up
Jan 01 00:00:20 user syslog: ifconfig eth0 up 2>/dev/null
Jan 01 00:00:20 user syslog: brctl addif br0 eth0 2>/dev/null
Jan 01 00:00:20 user kernel: device eth0 entered promiscuous mode
Jan 01 00:00:20 user kernel: br0: port 1(eth0) entering learning state
Jan 01 00:00:20 user kernel: br0: topology change detected, propagating
Jan 01 00:00:20 user kernel: br0: port 1(eth0) entering forwarding state
Jan 01 00:00:21 user syslog: ifconfig eth1 up
Jan 01 00:00:21 user syslog: ifconfig eth1 up 2>/dev/null
Jan 01 00:00:21 user syslog: brctl addif br0 eth1 2>/dev/null
Jan 01 00:00:21 user kernel: device eth1 entered promiscuous mode
Jan 01 00:00:21 user kernel: br0: port 2(eth1) entering learning state
Jan 01 00:00:21 user kernel: br0: topology change detected, propagating
Jan 01 00:00:21 user kernel: br0: port 2(eth1) entering forwarding state
Jan 01 00:00:21 user kernel: br0: port 1(eth0) entering disabled state
Jan 01 00:00:24 user kernel: Line 0: ADSL G.992 started
Jan 01 00:00:25 user syslog: wps_btn&
Jan 01 00:00:25 user syslog: WSCScan&
Jan 01 00:00:26 user kernel: iNIC Open ra0
Jan 01 00:00:26 user kernel: KLOB extended to 3 pools
Jan 01 00:00:26 user kernel: ADDR0 = 10000008, ADDR1 = 10100008
Jan 01 00:00:26 user kernel: CMD = 0016, STATUS = 04a0
Jan 01 00:00:26 user kernel: LATENCY = 40, CACHE LINE SIZE = 08
Jan 01 00:00:26 user kernel: INT LINE = 39
Jan 01 00:00:26 user kernel: Reset PCI Card
Jan 01 00:00:26 user kernel: ADDR0 = 10000008, ADDR1 = 10100008
Jan 01 00:00:26 user kernel: CMD = 0016, STATUS = 04a0
Jan 01 00:00:26 user kernel: INT LINE = 39
Jan 01 00:00:26 user kernel: ### LATENCY = 20, CACHE LINE SIZE = 08
Jan 01 00:00:26 user kernel: PDMA_RST_IDX = 0
Jan 01 00:00:26 user kernel: PDMA_GLO_CFG = 00000020
Jan 01 00:00:26 user kernel: TX_MAX_CNT0 = 00000080
Jan 01 00:00:26 user kernel: 2. reg = 00000020
Jan 01 00:00:26 user kernel: 2. PDMA_GLO_CFG = 00000065, reg = 00000065
Jan 01 00:00:26 user kernel: Op mode = 1
Jan 01 00:00:26 user kernel: BssidNum=1
Jan 01 00:00:26 user kernel: Wait for boot done...
Jan 01 00:00:26 user kernel: RACFG_CMD_BOOT_NOTIFY
Jan 01 00:00:26 user kernel: Open file: /etc/Wireless/RT2880/iNIC_ap.bin
Jan 01 00:00:26 user kernel: Open file: /var/iNIC_ap.dat
Jan 01 00:00:26 user kernel: RACFG_CMD_BOOT_INITCFG(0)
Jan 01 00:00:26 user kernel: RACFG_CMD_BOOT_INITCFG(1)
Jan 01 00:00:26 user kernel: RACFG_CMD_BOOT_INITCFG(2)
Jan 01 00:00:27 user kernel: Send Init Cfg Data Done(3 packets)
Jan 01 00:00:27 user kernel: RACFG_CMD_BOOT_UPLOAD(0)
Jan 01 00:00:27 user kernel: RACFG_CMD_BOOT_UPLOAD(1)
Jan 01 00:00:27 user kernel: RACFG_CMD_BOOT_UPLOAD(2)
Jan 01 00:00:27 user kernel: Line 0: ADSL G.992 channel analysis
Jan 01 00:00:27 user kernel:
Jan 01 00:00:27 user kernel: CRC:01 08 14 18 f3 ba d7 75 22 32 2e 35 2e 30 2e 31 22 00 00 00 32 30 31 32 30 33 30 38 00 00 00 00 00 00 00 00 f0 45 06 00
Jan 01 00:00:27 user kernel: Send RT2880iNIC Firmware Done
Jan 01 00:00:27 user kernel: ===================================
Jan 01 00:00:27 user kernel: version: "2.5.0.1"
Jan 01 00:00:27 user kernel: size:    411120 bytes
Jan 01 00:00:27 user kernel: date:    20120308
Jan 01 00:00:27 user kernel: ===================================
Jan 01 00:00:27 user kernel:
Jan 01 00:00:27 user kernel: Send STARTUP to RT2880iNIC
Jan 01 00:00:27 user kernel: Close Firmware file
Jan 01 00:00:27 user kernel: RACFG_CMD_BOOT_STARTUP
Jan 01 00:00:29 user kernel: Update MAC(0)=00:04:ed:e8:40:a0
Jan 01 00:00:29 user syslog: ifconfig ra0 up 2>/dev/null
Jan 01 00:00:29 user syslog: brctl addif br0 ra0 2>/dev/null
Jan 01 00:00:29 user kernel: device ra0 entered promiscuous mode
Jan 01 00:00:29 user kernel: br0: port 3(ra0) entering learning state
Jan 01 00:00:29 user kernel: br0: topology change detected, propagating
Jan 01 00:00:29 user kernel: br0: port 3(ra0) entering forwarding state
Jan 01 00:00:30 user syslog: ethctl eth0 vport query 2>/var/vcfgerr
Jan 01 00:00:30 user syslog: rm /var/vcfgerr
Jan 01 00:00:30 user syslog: ethctl eth1 vport query 2>/var/vcfgerr
Jan 01 00:00:30 user syslog: rm /var/vcfgerr
Jan 01 00:00:30 user syslog: rmmod vnet 2>/dev/null
Jan 01 00:00:30 user kernel: br0: port 3(ra0) entering disabled state
Jan 01 00:00:30 user kernel: br0: port 2(eth1) entering disabled state
Jan 01 00:00:30 user kernel: br0: port 3(ra0) entering learning state
Jan 01 00:00:30 user kernel: br0: port 2(eth1) entering learning state
Jan 01 00:00:30 user kernel: br0: topology change detected, propagating
Jan 01 00:00:30 user kernel: br0: port 3(ra0) entering forwarding state
Jan 01 00:00:30 user kernel: br0: topology change detected, propagating
Jan 01 00:00:30 user kernel: br0: port 2(eth1) entering forwarding state
Jan 01 00:00:30 user kernel: br0: port 1(eth0) entering learning state
Jan 01 00:00:30 user kernel: br0: topology change detected, propagating
Jan 01 00:00:30 user kernel: br0: port 1(eth0) entering forwarding state
Jan 01 00:00:31 daemon dnsmasq[91]: using nameserver 8.8.4.4#53
Jan 01 00:00:31 daemon dnsmasq[91]: using nameserver 8.8.8.8#53
Jan 01 00:00:31 user kernel: Line 0: ADSL link up, fast, us=672, ds=2368
Jan 01 00:00:32 daemon UPNPD[522]: HTTP listening on port 2800
Jan 01 00:00:32 daemon dnsmasq[91]: using nameserver 8.8.4.4#53
Jan 01 00:00:32 daemon dnsmasq[91]: using nameserver 8.8.8.8#53
Jan 01 00:00:33 daemon pppd[535]: PPPoATM setdevname_pppoatm
Jan 01 00:00:33 daemon pppd[535]: PPPoATM setdevname_pppoatm - SUCCESS
Jan 01 00:00:33 daemon pppd[535]: pppd 2.4.1 started by admin, uid 0
Jan 01 00:00:33 user kernel: br0: port 1(eth0) entering disabled state
Jan 01 00:00:33 daemon DHCP SERVER: DHCP request from 1c:4b:d6:7b:45:d3
Jan 01 00:00:33 daemon DHCP SERVER: DHCP ack to 1c:4b:d6:7b:45:d3
Jan 01 00:00:34 daemon pppd[535]: PPPoE: Terminating on signal 15.
Jan 01 00:00:34 daemon pppd[535]: Exit.
Jan 01 00:00:35 daemon pppd[633]: PPPoATM setdevname_pppoatm
Jan 01 00:00:35 daemon pppd[633]: PPPoATM setdevname_pppoatm - SUCCESS
Jan 01 00:00:35 daemon pppd[633]: pppd 2.4.1 started by admin, uid 0
Jan 01 00:00:35 daemon pppd[633]: PPP: Start to connect ...
Jan 01 00:00:35 daemon pppd[633]: Using interface ppp0_0_100_1
Jan 01 00:00:35 daemon pppd[633]: Connect: ppp_0_0_100_1 <-->
Jan 01 00:00:44 daemon pppd[633]: LCP: timeout sending Config-Requests
Jan 01 00:00:44 daemon pppd[633]: Connection terminated.
Jan 01 00:00:47 daemon pppd[633]: PPP: Start to connect ...
Jan 01 00:00:47 daemon pppd[633]: Using interface ppp0_0_100_1
Jan 01 00:00:47 daemon pppd[633]: Connect: ppp_0_0_100_1 <-->
Jan 01 00:00:56 daemon pppd[633]: LCP: timeout sending Config-Requests
Jan 01 00:00:56 daemon pppd[633]: Connection terminated.
Jan 01 00:00:59 daemon pppd[633]: PPP: Start to connect ...
Jan 01 00:00:59 daemon pppd[633]: Using interface ppp0_0_100_1
Jan 01 00:00:59 daemon pppd[633]: Connect: ppp_0_0_100_1 <-->
Jan 01 00:01:08 daemon pppd[633]: LCP: timeout sending Config-Requests
Jan 01 00:01:08 daemon pppd[633]: Connection terminated.
Jan 01 00:01:11 daemon pppd[633]: PPP: Start to connect ...
Jan 01 00:01:11 daemon pppd[633]: Using interface ppp0_0_100_1
Jan 01 00:01:11 daemon pppd[633]: Connect: ppp_0_0_100_1 <-->
Jan 01 00:01:20 daemon pppd[633]: LCP: timeout sending Config-Requests
Jan 01 00:01:20 daemon pppd[633]: Connection terminated.
Jan 01 00:01:23 daemon pppd[633]: PPP: Start to connect ...
Jan 01 00:01:23 daemon pppd[633]: Using interface ppp0_0_100_1
Jan 01 00:01:23 daemon pppd[633]: Connect: ppp_0_0_100_1 <-->
Jan 01 00:01:32 daemon pppd[633]: LCP: timeout sending Config-Requests
Jan 01 00:01:32 daemon pppd[633]: Connection terminated.
Jan 01 00:01:35 daemon pppd[633]: PPP: Start to connect ...
Jan 01 00:01:35 daemon pppd[633]: Using interface ppp0_0_100_1
Jan 01 00:01:35 daemon pppd[633]: Connect: ppp_0_0_100_1 <-->
Jan 01 00:01:44 daemon pppd[633]: LCP: timeout sending Config-Requests
Jan 01 00:01:44 daemon pppd[633]: Connection terminated.
Jan 01 00:01:47 daemon pppd[633]: PPP: Start to connect ...
Jan 01 00:01:47 daemon pppd[633]: Using interface ppp0_0_100_1
Jan 01 00:01:47 daemon pppd[633]: Connect: ppp_0_0_100_1 <-->
Jan 01 00:01:48 daemon pppd[633]: PPP LCP UP.
Jan 01 00:01:49 daemon pppd[633]: local IP address 111.69.
Jan 01 00:01:49 daemon pppd[633]: remote IP address 111.69.
Jan 01 00:01:49 daemon pppd[633]: primary   DNS address 202.37.101.1
Jan 01 00:01:49 daemon pppd[633]: secondary DNS address 202.37.101.2
Jan 01 00:01:50 daemon dnsmasq[91]: using nameserver 202.37.101.2#53
Jan 01 00:01:50 daemon dnsmasq[91]: using nameserver 202.37.101.1#53
Jan 01 00:01:50 daemon pppd[633]: Received valid IP address from server. Connection UP.
Jan 01 00:01:50 daemon pppd[633]: local LL address fe80::8576:4f52:3cec:3ec6
Jan 01 00:01:50 daemon pppd[633]: remote LL address fe80::0090:1a00:d7a3:50c7
Jan 01 00:01:50 user syslog: wan6Autod start..
Jan 01 00:01:50 user syslog: begin: interface: ppp_0_0_100_1 go to up
Jan 01 00:01:50 user syslog: Hop limit                : 0
Jan 01 00:01:50 user syslog: Stateful address conf.    : No
Jan 01 00:01:50 user syslog: Stateful other conf.      : No
Jan 01 00:01:50 user syslog: Router preference        : medium
Jan 01 00:01:50 user syslog: Router lifetime           : 1800 seconds
Jan 01 00:01:50 user syslog: Reachable time           : 0 milliseconds
Jan 01 00:01:50 user syslog: Retransmit time          : 0 milliseconds
Jan 01 00:01:50 user syslog: dhcp6c restart..
Jan 01 00:01:51 daemon dnsmasq[91]: using nameserver 202.37.101.2#53
Jan 01 00:01:51 daemon dnsmasq[91]: using nameserver 202.37.101.1#53
Jan 01 00:01:51 daemon UPNPD[522]: received signal 15, good-bye
Jan 01 00:01:53 daemon UPNPD[1286]: HTTP listening on port 2800
Jan 01 00:01:54 user syslog: end: interface: ppp_0_0_100_1 go to up
Jan 01 00:02:00 daemon DHCP SERVER: DHCPINFORM from 192.168.1.2
Jan 01 00:02:03 daemon DHCP SERVER: DHCPINFORM from 192.168.1.2

nzgeek

618 posts

Ultimate Geek

#1037873 6-May-2014 17:58

Something definitely seems to be wrong there. You've got full DSL sync at the 0:00:35 mark, but then you get 6 failed attempts at making a PPP connection. It's not until the 7th attempt at 0:01:47 that you actually connect successfully.

It certainly looks like something between you and Snap is misbehaving. The fact that it's happening on router boot-up may help if you need to reproduce the issue. And definitely do get Snap support on the phone the next time the problem comes up. I get the feeling they'll need to do something, which could range from a simple port reset to getting Chorus to reconfigure the connection.

jdmatt

28 posts

Geek

#1037898 6-May-2014 18:53

nzgeek: Something definitely seems to be wrong there. You've got full DSL sync at the 0:00:35 mark, but then you get 6 failed attempts at making a PPP connection. It's not until the 7th attempt at 0:01:47 that you actually connect successfully.

It certainly looks like something between you and Snap is misbehaving. The fact that it's happening on router boot-up may help if you need to reproduce the issue. And definitely do get Snap support on the phone the next time the problem comes up. I get the feeling they'll need to do something, which could range from a simple port reset to getting Chorus to reconfigure the connection.

Yes I thought something was a miss when I saw that it had a few attempts at it, anyway that connection only lasted till 4pm today, so got snap on the phone while it was cycling to make a PPP connection and they couldn't see any authentication attempts on their end. So they have done a port refresh and no drops yet at this stage but still early days. Hope it fixes the issue. Will report back in a few days.

jdmatt

28 posts

Geek

#1038073 7-May-2014 08:35

It seems a port refresh didn't help fix the issues I was experiencing, no connection this morning. Will contact snap again and try and find what is causing this arr.

I managed to capture the log of when the connection dropped.

2014-05-07 00:41:04   Syslog.Info   192.168.1.254   May 07 00:41:04 *ú` home -- MARK --
2014-05-07 01:04:17   Daemon.Info   192.168.1.254   May 07 01:04:17   home pppd[6491]: No response to 6 echo-requests
2014-05-07 01:04:17   Daemon.Notice   192.168.1.254   May 07 01:04:17   home pppd[6491]: Serial link appears to be disconnected.
2014-05-07 01:04:17   Daemon.Notice   192.168.1.254   May 07 01:04:17   home pppd[6491]: Clear IP addresses. Connection DOWN.
2014-05-07 01:04:17   Daemon.Notice   192.168.1.254   May 07 01:04:17   home pppd[6491]: Clear IP addresses.
2014-05-07 01:04:18   User.Info   192.168.1.254   May 07 01:04:17   home syslog: begin: interface: ppp_0_0_100_1 go to down
2014-05-07 01:04:18   User.Info   192.168.1.254   May 07 01:04:17   home syslog: end: interface: ppp_0_0_100_1 go to down
2014-05-07 01:04:18   Daemon.Info   192.168.1.254   May 07 01:04:18   home pppd[6491]: PPPoE: Terminating on signal 15.
2014-05-07 01:04:23   Daemon.Notice   192.168.1.254   May 07 01:04:23   home pppd[6491]: Connection terminated.
2014-05-07 01:04:23   Daemon.Info   192.168.1.254   May 07 01:04:23   home pppd[6491]: Connect time 107.6 minutes.
2014-05-07 01:04:23   Daemon.Info   192.168.1.254   May 07 01:04:23   home pppd[6491]: Sent 498 bytes, received 10424 bytes.
2014-05-07 01:04:23   User.Warning   192.168.1.254   May 07 01:04:23   home kernel: dev_shutdown, dec ppp device refcnt, dev->refcnt=9
2014-05-07 01:04:24   User.Emerg   192.168.1.254   May 07 01:04:23   home kernel: unregister_netdevice: waiting for ppp_0_0_100_1 to become free. Usage count = -1
2014-05-07 01:04:24   User.Warning   192.168.1.254   May 07 01:04:23   home kernel: dev->name = ppp_0_0_100_1, dev->refcnt=-1
2014-05-07 01:04:24   User.Warning   192.168.1.254   May 07 01:04:23   home kernel: after reset to 0, dev->refcnt=0
2014-05-07 01:04:27   Daemon.Info   192.168.1.254   May 07 01:04:26   home pppd[6491]: Exit.
2014-05-07 01:04:27   Daemon.Info   192.168.1.254   May 07 01:04:26   home pppd[12754]: PPPoATM setdevname_pppoatm
2014-05-07 01:04:27   Daemon.Info   192.168.1.254   May 07 01:04:26   home pppd[12754]: PPPoATM setdevname_pppoatm - SUCCESS
2014-05-07 01:04:27   Daemon.Notice   192.168.1.254   May 07 01:04:26   home pppd[12754]: pppd 2.4.1 started by admin, uid 0
2014-05-07 01:04:27   Daemon.Notice   192.168.1.254   May 07 01:04:26   home pppd[12754]: PPP: Start to connect ...
2014-05-07 01:04:27   Daemon.Info   192.168.1.254   May 07 01:04:26   home pppd[12754]: Using interface ppp0_0_100_1
2014-05-07 01:04:27   Daemon.Notice   192.168.1.254   May 07 01:04:26   home pppd[12754]: Connect: ppp_0_0_100_1 <-->
2014-05-07 01:04:36   Daemon.Warning   192.168.1.254   May 07 01:04:35   home pppd[12754]: LCP: timeout sending Config-Requests
2014-05-07 01:04:36   Daemon.Notice   192.168.1.254   May 07 01:04:35   home pppd[12754]: Connection terminated.
2014-05-07 01:05:00   Daemon.Notice   192.168.1.254   May 07 01:04:59   home pppd[12754]: Connection terminated.
2014-05-07 01:05:03   Daemon.Notice   192.168.1.254   May 07 01:05:02   home pppd[12754]: PPP: Start to connect ...
2014-05-07 01:05:03   Daemon.Info   192.168.1.254   May 07 01:05:02   home pppd[12754]: Using interface ppp0_0_100_1
2014-05-07 01:05:03   Daemon.Notice   192.168.1.254   May 07 01:05:02   home pppd[12754]: Connect: ppp_0_0_100_1 <-->
2014-05-07 01:05:12   Daemon.Warning   192.168.1.254   May 07 01:05:11   home pppd[12754]: LCP: timeout sending Config-Requests
2014-05-07 01:05:12   Daemon.Notice   192.168.1.254   May 07 01:05:11   home pppd[12754]: Connection terminated.

Lorenceo

904 posts

Ultimate Geek

Trusted

#1038196 7-May-2014 11:19

What settings are you using on the routers?
I see both PPPoE and PPPoA mentioned in those logs. Is it possible you've set up both a PPPoE and a PPPoA connection, and your router is cycling between them attempting to connect both at the same time, with one being rejected by Snap?

See this page for the required connection settings: http://www.snap.net.nz/support/content/1/17/en/general-settings.html

Quic Broadband

Move to New Zealand's best fibre broadband service (affiliate link). Free setup code: R587125ERQ6VE. Note that to use Quic Broadband you must be comfortable with configuring your own router.

jdmatt

28 posts

Geek

#1038235 7-May-2014 11:41

Lorenceo: What settings are you using on the routers?
I see both PPPoE and PPPoA mentioned in those logs. Is it possible you've set up both a PPPoE and a PPPoA connection, and your router is cycling between them attempting to connect both at the same time, with one being rejected by Snap?

See this page for the required connection settings: http://www.snap.net.nz/support/content/1/17/en/general-settings.html

Have input settings as per snaps config only PPPoA vci/vci,pap etc so am unsure why it has PPPoE in there, its getting all a bit beyond me, here is a screenshot of adsl settings.

Lorenceo

904 posts

Ultimate Geek

Trusted

#1038407 7-May-2014 15:18

That all looks correct to me. If your settings are correct and you get the same issue with two different routers it's likely something you cannot resolve from your end, and will require attention by Snap/Chorus.
Does your line lose sync when your internet connection drops, or only the PPP session?

jdmatt

28 posts

Geek

#1038527 7-May-2014 18:44

No I don't lose line sync, but it cannot renegotiate a PPP connection. Its driving me nuts, regretting the switch from telecom now.

Here is the netgear(DG834gt) router log, just goes into that same cycle as the billion BiPAC 7800n.

Sat, 2000-01-01 00:00:30 - Initialize LCP.
Sat, 2000-01-01 00:00:30 - LCP is allowed to come up.
Sat, 2000-01-01 00:00:34 - PAP authentication success
Sat, 2000-01-01 00:00:38 - Send out NTP request to time-g.netgear.com
Wed, 2014-05-07 05:44:31 - Receive NTP Reply from time-g.netgear.com
Wed, 2014-05-07 05:45:16 - Administrator login successful - IP:192.168.0.2
Wed, 2014-05-07 06:20:52 - LCP down.
Wed, 2014-05-07 06:23:32 - Initialize LCP.
Wed, 2014-05-07 06:23:32 - LCP is allowed to come up.
Wed, 2014-05-07 06:24:33 - Initialize LCP.
Wed, 2014-05-07 06:24:33 - LCP is allowed to come up.
Wed, 2014-05-07 06:25:18 - Initialize LCP.
Wed, 2014-05-07 06:25:18 - LCP is allowed to come up.
Wed, 2014-05-07 06:26:19 - Initialize LCP.
Wed, 2014-05-07 06:26:19 - LCP is allowed to come up.
Wed, 2014-05-07 06:27:19 - Initialize LCP.
Wed, 2014-05-07 06:27:19 - LCP is allowed to come up.

I've tried pretty much everything I can at my end, from factory resets, to firmware flash, re-entering snap settings to wiring directly into etp point. Hopefully I can now rule out that the issue is not at my end. On phone again to snap I guess.

wongtop

565 posts

Ultimate Geek

#1038554 7-May-2014 19:31

Its probably no consolation, but snap works fine on my Netgear 834G. If you want me to try your details out on my Netgear, then PM me.

Frontliner

67 posts

Master Geek

#1041215 10-May-2014 00:43

Been having a similar issue here, using the ASUS DSL-N55U. Here is an excerpt of the log in the past 24 hours. We do lose sync however. In my case it might just be ASUS and their dodgy, horribly buggy firmware.

[code]May 9 11:53:57 WAN Connection: Ethernet link down.
May 9 11:53:57 stop_nat_rules: apply the redirect_rules!
May 9 11:54:46 pppd[324]: Serial link appears to be disconnected.
May 9 11:54:52 pppd[324]: Connection terminated.
May 9 11:54:52 pppd[324]: Modem hangup
May 9 11:55:02 pppd[324]: Connected to 00:aa:bb:01:23:45 via interface eth2.1.1
May 9 11:55:02 pppd[324]: Connect: ppp0 <--> eth2.1.1
May 9 11:55:09 pppd[324]: PAP authentication succeeded
May 9 11:55:09 pppd[324]: peer from calling number 00:AA:BB:01:23:45 authorized
May 9 11:55:09 pppd[324]: local IP address [removed]
May 9 11:55:09 pppd[324]: remote IP address [removed]
May 9 11:55:09 pppd[324]: primary   DNS address 202.37.101.1
May 9 11:55:09 pppd[324]: secondary DNS address 202.37.101.2
May 9 11:55:09 start_nat_rules: apply the nat_rules(/tmp/nat_rules_ppp0_eth2.1.1)!
May 9 11:55:09 rc_service: ip-up 1518:notify_rc stop_upnp
May 9 11:55:09 miniupnpd[1430]: received signal 15, good-bye
May 9 11:55:09 rc_service: ip-up 1518:notify_rc start_upnp
May 9 11:55:09 miniupnpd[1547]: HTTP listening on port 56442
May 9 11:55:09 miniupnpd[1547]: Listening for NAT-PMP traffic on port 5351
May 9 11:55:12 WAN Connection: WAN was restored.
May 9 12:03:22 pppd[324]: Serial link appears to be disconnected.
May 9 12:03:23 WAN Connection: Fail to connect with some issues.
May 9 12:03:23 stop_nat_rules: apply the redirect_rules!
May 9 12:03:24 WAN Connection: Ethernet link down.
May 9 12:03:28 pppd[324]: Connection terminated.
May 9 12:03:28 pppd[324]: Modem hangup
May 9 12:03:38 pppd[324]: Connected to 00:aa:bb:01:23:45 via interface eth2.1.1
May 9 12:03:38 pppd[324]: Connect: ppp0 <--> eth2.1.1
May 9 12:03:45 pppd[324]: PAP authentication succeeded
May 9 12:03:45 pppd[324]: peer from calling number 00:AA:BB:01:23:45 authorized
May 9 12:03:45 pppd[324]: local IP address [removed]
May 9 12:03:45 pppd[324]: remote IP address [removed]
May 9 12:03:45 pppd[324]: primary   DNS address 202.37.101.1
May 9 12:03:45 pppd[324]: secondary DNS address 202.37.101.2
May 9 12:03:45 start_nat_rules: apply the nat_rules(/tmp/nat_rules_ppp0_eth2.1.1)!
May 9 12:03:45 rc_service: ip-up 1560:notify_rc stop_upnp
May 9 12:03:45 miniupnpd[1547]: received signal 15, good-bye
May 9 12:03:45 rc_service: ip-up 1560:notify_rc start_upnp
May 9 12:03:45 miniupnpd[1589]: HTTP listening on port 45253
May 9 12:03:45 miniupnpd[1589]: Listening for NAT-PMP traffic on port 5351
May 9 12:03:47 WAN Connection: WAN was restored.
May 9 12:04:37 WAN Connection: Ethernet link down.
May 9 12:04:37 stop_nat_rules: apply the redirect_rules!
May 9 12:05:27 pppd[324]: Serial link appears to be disconnected.
May 9 12:05:33 pppd[324]: Connection terminated.
May 9 12:05:33 pppd[324]: Modem hangup
May 9 12:05:43 pppd[324]: Connected to 00:aa:bb:01:23:45 via interface eth2.1.1
May 9 12:05:43 pppd[324]: Connect: ppp0 <--> eth2.1.1
May 9 12:05:50 pppd[324]: PAP authentication succeeded
May 9 12:05:50 pppd[324]: peer from calling number 00:AA:BB:01:23:45 authorized
May 9 12:05:50 pppd[324]: local IP address [removed]
May 9 12:05:50 pppd[324]: remote IP address [removed]
May 9 12:05:50 pppd[324]: primary   DNS address 202.37.101.1
May 9 12:05:50 pppd[324]: secondary DNS address 202.37.101.2
May 9 12:05:51 rc_service: ip-up 1602:notify_rc stop_upnp
May 9 12:05:51 miniupnpd[1589]: received signal 15, good-bye
May 9 12:05:51 rc_service: ip-up 1602:notify_rc start_upnp
May 9 12:05:51 miniupnpd[1630]: HTTP listening on port 34757
May 9 12:05:51 miniupnpd[1630]: Listening for NAT-PMP traffic on port 5351
May 9 12:07:05 WAN Connection: WAN was restored.
May 9 12:07:05 start_nat_rules: apply the nat_rules(/tmp/nat_rules_ppp0_eth2.1.1)!
May 9 12:30:30 rc_service: httpd 293:notify_rc restart_wan_if 0
May 9 12:30:30 pppd[324]: Connection terminated.
May 9 12:30:30 stop_wan(): perform DHCP release
May 9 12:30:30 WAN Connection: Fail to connect with some issues.
May 9 12:30:30 stop_nat_rules: apply the redirect_rules!
May 9 12:30:35 WAN Connection: WAN was exceptionally disconnected.
May 9 12:30:41 rc_service: httpd 293:notify_rc restart_wan_if 0
May 9 12:30:41 stop_wan(): perform DHCP release
May 9 12:30:43 kernel: eth2.1.1: Setting MAC address to 10 bf 48 81 21 a0.
May 9 12:30:43 pppd[1651]: pppd 2.4.5 started by admin, uid 0
May 9 12:30:43 pppd[1651]: Connected to 00:aa:bb:01:23:45 via interface eth2.1.1
May 9 12:30:43 pppd[1651]: Connect: ppp0 <--> eth2.1.1
May 9 12:30:45 WAN Connection: Ethernet link down.
May 9 12:30:47 pppd[1651]: PAP authentication succeeded
May 9 12:30:47 pppd[1651]: peer from calling number 00:AA:BB:01:23:45 authorized
May 9 12:30:47 pppd[1651]: local IP address [removed]
May 9 12:30:47 pppd[1651]: remote IP address [removed]
May 9 12:30:47 pppd[1651]: primary   DNS address 202.37.101.1
May 9 12:30:47 pppd[1651]: secondary DNS address 202.37.101.2
May 9 12:30:47 start_nat_rules: apply the nat_rules(/tmp/nat_rules_ppp0_eth2.1.1)!
May 9 12:30:47 rc_service: ip-up 1655:notify_rc stop_upnp
May 9 12:30:47 miniupnpd[1630]: received signal 15, good-bye
May 9 12:30:47 rc_service: ip-up 1655:notify_rc start_upnp
May 9 12:30:47 miniupnpd[1684]: HTTP listening on port 52502
May 9 12:30:47 miniupnpd[1684]: Listening for NAT-PMP traffic on port 5351
May 9 12:30:50 WAN Connection: WAN was restored.
May 9 12:30:54 start_nat_rules: apply the nat_rules(/tmp/nat_rules_ppp0_eth2.1.1)!
May 9 12:30:54 zcip client: configured 169.254.25.234

nzgeek

618 posts

Ultimate Geek

#1041283 10-May-2014 11:32

The "Serial link appears to be disconnected" and "Modem hangup" entries make it sound like you're losing DSL sync.

If you catch one of these disconnects in the act, go check the DSL sync light on the modem and see what it's doing. That'll tell you whether it's the link between you modem and the exchange/cabinet that's going down, or the connection between you modem and Snap.

Another thing: what's your line attenuation (down) like? It's been reported on other forums that your router often has problems starting connected when the number is high, i.e. above 30dB or so. The problem is the chipset that does the ADSL connection. There's no way to fix it other than to replace the modem with one that uses a more reliable chipset (e.g. a Broadcom chipset).

RalphFromSnap

776 posts

Ultimate Geek

Trusted

Snap Internet

#1041284 10-May-2014 11:41

Hi All,

Strange problem! @jdmatt & @frontliner can you post your location (City/Town/Suburb) so I can pass to our core team for more investigation?

Cheers,
TheRalph

Snap

0800 BROADBAND (276 232)
www.snap.net.nz

@SnapInternet on Twitter
Snap Internet on Facebook

Our Social Media Team:
^RO Ricky - Technical Lead
^AT Ashleigh - Retail Marketing Coordinator

jdmatt

28 posts

Geek

#1041402 10-May-2014 17:06

Sorry for a late update, Snap sent out a Chorus tech on Thursday, a very helpful fellow. He checked lines and no problem was found, told him that problem has only popped up after switching ISP. So he got straight into switching me over to another port in the Dslam. First four hours were good with no drop outs but then got the dreaded lcp timeout again. So did the usual restart and it happened again, So I pulled it out of the wall that night and walked away before my rage split over onto the the poor routers. Next morning I hooked everything back up with factory reset but changed the mtu to 1492, so far this has seem to have fixed the problem at this stage. Touch-wood.

Can some explain why a small change it the mtu could fix this issue? I'm not even sure if this change was what fixed it or it could have been the verbal abuse I hurled at it the night before! But I thought 1500 was the default size for pppoa? I haven't tested this theory on the netgear router yet but it also had a 1500 mtu.

I would like to say that so far I am pretty happy with my connection "when" it works, last night I had a good netflix session and was able to stream 720p whereas on telecom was only able to achieve 384/480SD so very happy on that side of things.

@nzgeek, yes I do have a terrible downstream attenuation, a whopping stable 63.5dB but this is due to the distance from my exchange around 7km. I Sync around 2400kbps @12dB SNR, have tweaked SNR in past to sync stable around 3400kbps @6dB. Although I think the attenuation in this case is not relevant due to past experiences on telecom where I have had stable connection for weeks at a time, and the problem only presenting it self after ISP change. Also both routers have a broadcom chipset.

@RalphFromSnap, Hey Ralph cheers, I think your team is onto my problem and hopefully it is close to being resolved but my location is Ashburton/Chertsey CY. It would be good to know what was causing this problem.

1 | 2