Print

Please login or register.
1 Hour 1 Day 1 Week 1 Month Forever
Login with username, password and session length

[hilaireg]

Hi folks,

Noticed that the router is off (behind) by 1 hour with the following settings:

Time Zone = GMT -05:00 Time (US/Canada), Toronto
Enabled Daylight Saving Time = Selected
DST Offset = +1

NTP Server = Enabled
NTP Server = time.chu.nrc.ca


Same settings on DGL-4100, DNS-323, and DNS-343 work as expected; seems to indicate that DST may not be functioning as expected.  

Anyone else running F/W 1.01 with the above settings can confirm proper operation?

Cheers,

[FurryNutz]

I'm using -7 Mtn
DST enable and using time.nist.gov as a server and time is correct for me in my zone.

using your settings I'm getting the following time accounting that I'm physically in a different zone:
Monday, June 04, 2012 10:22:26 AM est...

Is this correct?

If I use same zone and time.nist.gov, i get the same time frame.

[hilaireg]

Interesting; looking at the logs and the router time with my settings above, it displays -1 hour to my current time.

I have all of my network equipment (forest root controller, dns, printers, etc.) pointing to 'time.chu.nrc.ca' and a force sync reports back with the current time settings ... this suggests that NTP resolution is happening two-way and therefore working - except for the DIR-857.

I'm at a client site at the moment, when I get back to the home office, I'll double-check the logs and router to see if a time resync has occurred.

Cheers,

[hilaireg]

Well ...

I enabled all of the logging features, cleared the existing logs, restarted the router.  There are no entries in the logs indicating any form of attempt to obtain time from an NTP server ... and yes, the options are enabled as per my original post.

Here's a copy of the log post-startup; note that personal identification information has been search/replaced.

Code: [Select]

Jun  4 16:52:15 debug  Debu: Joining group 224.0.0.251 upstream on IF address 999.999.999.999
Jun  4 16:52:15 debug  Debu: Route activate request 999.999.999.999 to 224.0.1.24 is from myself, Ignoring it !
Jun  4 16:52:15 debug  Debu: Joining group 224.0.1.24 upstream on IF address 999.999.999.999
Jun  4 16:52:14 debug  Debu: Leaving group 224.0.1.24 upstream on IF address 999.999.999.999
Jun  4 16:51:54 info  SMTP client send Email successfully
Jun  4 16:51:51 info  [email sent to: [email protected] ] Monday, June 04, 2012 16:51:51
Jun  4 16:51:49 debug  Debu: Route activate request 999.999.999.999 to 224.0.1.24 is from myself, Ignoring it !
Jun  4 16:51:43 info  SMTP (Email) server [SMTP.MYISP.COM] is at IP address 888.888.888.888:25
Jun  4 16:51:39 debug  gpio create pidfile /var/run/gpio_wan_green.pid
Jun  4 16:49:19 notice  HTTP listening on port 10579
Jun  4 16:49:17 notice  HTTP listening on port 65530
Jun  4 16:49:15 info  Service  D-link HNAP Service  (/var/etc/avahi/services/dhnap.service) successfully established.
Jun  4 16:49:15 info  Service  D-Link DIR-857 Configuration Utility  (/var/etc/avahi/services/http.service) successfully established.
Jun  4 16:49:15 info  Service  MYDIR857  (/var/etc/avahi/services/mtdaap.service) successfully established.
Jun  4 16:49:15 info  Server startup complete. Host name is MYDIR857.local. Local service cookie is 1311551786.
Jun  4 16:49:14 notice  ( (800)action 1,major 8,minor 0)
Jun  4 16:49:14 notice  [   31.173182] sd 0:0:0:0: [sda] Attached SCSI removable disk
Jun  4 16:49:14 notice  [   31.168657] sd 0:0:0:0: Attached scsi generic sg0 type 0
Jun  4 16:49:14 notice  [   31.148828] scsi 0:0:0:0: Direct-Access     Generic  STORAGE DEVICE   0206 PQ: 0 ANSI: 0
Jun  4 16:49:14 info  Registering new address record for 192.168.200.1 on br0.IPv4.
Jun  4 16:49:14 info  Registering new address record for fe80::baa3:86ff:fe4f:6636 on br0.*.
Jun  4 16:49:14 info  Network interface enumeration completed.
Jun  4 16:49:14 info  New relevant interface br0.IPv4 for mDNS.
Jun  4 16:49:14 info  Joining mDNS multicast group on interface br0.IPv4 with address 192.168.200.1.
Jun  4 16:49:14 info  New relevant interface br0.IPv6 for mDNS.
Jun  4 16:49:14 info  Joining mDNS multicast group on interface br0.IPv6 with address fe80::baa3:86ff:fe4f:6636.
Jun  4 16:49:14 info  Loading service file /var/etc/avahi/services/mtdaap.service.
Jun  4 16:49:14 info  Loading service file /var/etc/avahi/services/http.service.
Jun  4 16:49:14 info  Loading service file /var/etc/avahi/services/dhnap.service.
Jun  4 16:49:14 info  avahi-daemon 0.6.30 starting up.
Jun  4 16:49:14 info  Successfully dropped root privileges.
Jun  4 16:49:14 info  Found user 'root' (UID 0) and group 'root' (GID 0).
Jun  4 16:49:14 debug  Debu: Route activate request 999.999.999.999 to 224.0.1.24 is from myself, Ignoring it !
Jun  4 16:49:14 debug  Debu: Joining group 224.0.1.24 upstream on IF address 999.999.999.999
Jun  4 16:49:13 info  [   30.152961] USB Mass Storage support registered.
Jun  4 16:49:13 info  [   30.152884] usbcore: registered new interface driver usb-storage
Jun  4 16:49:13 info  [   30.146494] scsi0 : usb-storage 1-1:1.0
Jun  4 16:49:13 info  [   30.145156] Initializing USB Mass Storage driver...
Jun  4 16:49:13 debug  [   29.948203] jcp_command_register: new command registered EXEC SCANNER DISCONNECT
Jun  4 16:49:13 debug  [   29.948150] jcp_command_register: new command registered EXEC SCANNER CONNECT
Jun  4 16:49:13 debug  [   29.948089] jcp_command_register: new command registered GET USB_DEVICE_LIST
Jun  4 16:49:13 debug  [   29.948030] jcp_command_register: new command registered GET SCANNER_STATUS
Jun  4 16:49:13 debug  [   29.947984] jcp_command_register: new command registered GET SCANNER PORT_NAME
Jun  4 16:49:13 debug  [   29.947915] jcp_command_register: new command registered GET USB_PORT_NAME
Jun  4 16:49:13 info  [   29.776469] usbcore: registered new interface driver sxuptp_driver
Jun  4 16:49:13 info  [   29.773019] sxuptp_driver: * If#=0 Alt=0 #EPs=2 Cls=0x08 SubCls=0x06 Prot=0x50
Jun  4 16:49:13 info  [   29.772888] sxuptp_driver: S(0x02): 000000000206
Jun  4 16:49:13 info  [   29.772824] sxuptp_driver: P(0x04): USB Storage
Jun  4 16:49:13 info  [   29.772761] sxuptp_driver: M(0x03): Generic
Jun  4 16:49:13 info  [   29.772679] sxuptp_driver: VID:0x05e3 PID:0x0727
Jun  4 16:49:13 debug  [   29.566674] sxuptp: sxuptp_keepalive_thread start
Jun  4 16:49:13 info  read /var/tmp/hosts - 1 addresses
Jun  4 16:49:13 info  read /etc/hosts - 2 addresses
Jun  4 16:49:13 info  using nameserver 444.444.444.444#53
Jun  4 16:49:13 info  using nameserver 555.555.555.555#53
Jun  4 16:49:13 info  reading /etc/resolv.conf
Jun  4 16:49:13 info  compile time options: IPv6 GNU-getopt no-MMU ISC-leasefile no-DOCTOR no-NOWILD no-DBus no-I18N TFTP
Jun  4 16:49:13 info  started, version 2.45 cachesize 150
Jun  4 16:49:12 debug  gpio create pidfile /var/run/gpio_power.pid
Jun  4 16:49:11 info  avahi-daemon 0.6.30 exiting.
Jun  4 16:49:11 info  Leaving mDNS multicast group on interface br0.IPv4 with address 192.168.200.1.
Jun  4 16:49:11 info  Leaving mDNS multicast group on interface br0.IPv6 with address fe80::baa3:86ff:fe4f:6636.
Jun  4 16:49:10 info  exiting on receipt of SIGTERM
Jun  4 16:49:10 notice  received signal 15, good-bye
Jun  4 16:49:10 notice  received signal 15, good-bye
Jun  4 16:49:10 notice  pppd sent restart signal to rc
Jun  4 16:49:10 notice  pppd check for rc to be idle ?
Jun  4 16:49:10 notice  secondary DNS address 555.555.555.555
Jun  4 16:49:10 notice  primary   DNS address 444.444.444.444
Jun  4 16:49:10 notice  ipcp_up: remote PPP IP address 777.777.777.777
Jun  4 16:49:10 notice  ipcp_up: local PPP IP address 999.999.999.999
Jun  4 16:49:10 notice  ipcp_up: Open /var/tmp/pptp_server_ip.txt (l2tp_server_ip.txt) fail or Using PPPoE
Jun  4 16:49:10 debug  peerdns2 : 555.555.555.555
Jun  4 16:49:10 debug  peerdns1 : 444.444.444.444
Jun  4 16:49:10 debug  ppp create_resolv in ipcp
Jun  4 16:49:10 debug  sent [IPCP ConfAck id=0x50 'addr 777.777.777.777']
Jun  4 16:49:10 debug  rcvd [IPCP ConfReq id=0x50 'addr 777.777.777.777']
Jun  4 16:49:09 debug  rcvd [IPCP ConfAck id=0x2 'addr 999.999.999.999' 'ms-dns1 444.444.444.444' 'ms-dns3 555.555.555.555']
Jun  4 16:49:09 debug  sent [IPCP ConfReq id=0x2 'addr 999.999.999.999' 'ms-dns1 444.444.444.444' 'ms-dns3 555.555.555.555']
Jun  4 16:49:09 debug  rcvd [IPCP ConfNak id=0x1 'addr 999.999.999.999' 'ms-dns1 444.444.444.444' 'ms-dns3 555.555.555.555']
Jun  4 16:49:09 debug  sent [IPCP ConfReq id=0x1 'addr 0.0.0.0' 'ms-dns1 0.0.0.0' 'ms-dns3 0.0.0.0']
Jun  4 16:49:09 notice  peer from calling number 00:26:82:FD:8A:50 authorized
Jun  4 16:49:09 notice  PAP authentication succeeded
Jun  4 16:49:09 debug  rcvd [PAP AuthAck id=0x1   ]
Jun  4 16:49:09 debug  rcvd [LCP EchoRep id=0x0 magic=0x41572f27]
Jun  4 16:49:09 debug  sent [PAP AuthReq id=0x1 user= [email protected]  password='hidden']
Jun  4 16:49:09 debug  sent [LCP EchoReq id=0x0 magic=0x91fd5d88]
Jun  4 16:49:09 debug  rcvd [LCP ConfAck id=0x1 'mru 1492' 'magic 0x91fd5d88']
Jun  4 16:49:09 debug  sent [LCP ConfAck id=0xc6 'mru 1492' 'auth pap' 'magic 0x41572f27']
Jun  4 16:49:09 debug  rcvd [LCP ConfReq id=0xc6 'mru 1492' 'auth pap' 'magic 0x41572f27']
Jun  4 16:49:09 debug  sent [LCP ConfReq id=0x1 'mru 1492' 'magic 0x91fd5d88']
Jun  4 16:49:09 notice  Connect: ppp0 '--' eth1
Jun  4 16:49:09 info  Using interface ppp0
Jun  4 16:49:09 debug  using channel 1
Jun  4 16:49:09 info  PPP session is 1
Jun  4 16:49:09 debug  PADS: Service-Name: ''
Jun  4 16:49:08 notice  HTTP listening on port 55992
Jun  4 16:49:07 info  disable write rom conf.
Jun  4 16:49:07 info  disable write rom conf.
Jun  4 16:49:06 notice  HTTP listening on port 65530
Jun  4 16:49:05 info  Service  D-link HNAP Service  (/var/etc/avahi/services/dhnap.service) successfully established.
Jun  4 16:49:05 info  Service  D-Link DIR-857 Configuration Utility  (/var/etc/avahi/services/http.service) successfully established.
Jun  4 16:49:05 info  Service  MYDIR857  (/var/etc/avahi/services/mtdaap.service) successfully established.
Jun  4 16:49:05 info  Server startup complete. Host name is MYDIR857.local. Local service cookie is 3230035688.
Jun  4 16:49:04 info  Registering new address record for 192.168.200.1 on br0.IPv4.
Jun  4 16:49:04 info  Registering new address record for fe80::baa3:86ff:fe4f:6636 on br0.*.
Jun  4 16:49:04 info  Network interface enumeration completed.
Jun  4 16:49:04 info  New relevant interface br0.IPv4 for mDNS.
Jun  4 16:49:04 info  Joining mDNS multicast group on interface br0.IPv4 with address 192.168.200.1.
Jun  4 16:49:04 info  New relevant interface br0.IPv6 for mDNS.
Jun  4 16:49:04 info  Joining mDNS multicast group on interface br0.IPv6 with address fe80::baa3:86ff:fe4f:6636.
Jun  4 16:49:04 info  Loading service file /var/etc/avahi/services/mtdaap.service.
Jun  4 16:49:04 info  Loading service file /var/etc/avahi/services/http.service.
Jun  4 16:49:04 info  Loading service file /var/etc/avahi/services/dhnap.service.
Jun  4 16:49:04 info  avahi-daemon 0.6.30 starting up.
Jun  4 16:49:04 info  Successfully dropped root privileges.
Jun  4 16:49:04 info  Found user 'root' (UID 0) and group 'root' (GID 0).
Jun  4 16:49:04 info  rp_pppoe =' read pppoe_conn_session error or first time dial
Jun  4 16:49:03 notice  pppd 2.4.3 started by root, uid 0
Jun  4 16:49:03 info  RP-PPPoE plugin inform wantimer to reset auth, discovery variable
Jun  4 16:49:03 info  RP-PPPoE plugin version 3.3 compiled against pppd 2.4.3
Jun  4 16:49:03 info  Plugin /lib/pppd/2.4.3/rp-pppoe.so loaded.
Jun  4 16:49:03 info  read /var/tmp/hosts - 1 addresses
Jun  4 16:49:03 info  read /etc/hosts - 2 addresses
Jun  4 16:49:03 info  compile time options: IPv6 GNU-getopt no-MMU ISC-leasefile no-DOCTOR no-NOWILD no-DBus no-I18N TFTP
Jun  4 16:49:03 info  started, version 2.45 cachesize 150
Jun  4 16:49:02 debug  gpio create pidfile /var/run/gpio_power.pid
Jun  4 16:49:01 info  [Initialized, firmware version: 1.01 ]
Jun  4 16:49:00 info  [    9.977341] br0: port 1(eth0) entering forwarding state
Jun  4 16:49:00 info  [    8.983413] br0: port 1(eth0) entering learning state
Jun  4 16:49:00 info  [    8.983379] br0: port 1(eth0) entering learning state
Jun  4 16:49:00 info  [    8.947652] device eth0 entered promiscuous mode
Jun  4 16:49:00 info  [    6.471925] usb 1-1: SerialNumber: 000000000206
Jun  4 16:49:00 info  [    6.471905] usb 1-1: Manufacturer: Generic
Jun  4 16:49:00 info  [    6.471887] usb 1-1: Product: USB Storage
Jun  4 16:49:00 info  [    6.471863] usb 1-1: New USB device strings: Mfr=3, Product=4, SerialNumber=2
Jun  4 16:49:00 info  [    6.471826] usb 1-1: New USB device found, idVendor=05e3, idProduct=0727
Jun  4 16:49:00 info  [    6.267362] usb 1-1: new high speed USB device number 2 using dwc_otg
Jun  4 16:49:00 info  [    5.988233] hub 2-0:1.0: 1 port detected
Jun  4 16:49:00 info  [    5.988184] hub 2-0:1.0: USB hub found
Jun  4 16:49:00 info  [    5.986613] usb usb2: SerialNumber: lm1
Jun  4 16:49:00 info  [    5.986591] usb usb2: Manufacturer: uClinux 2.6.36+ dwc_otg_hcd
Jun  4 16:49:00 info  [    5.986571] usb usb2: Product: DWC OTG Controller


[hilaireg]

Well, I've been monitoring the DIR-857 as well as my other devices and I'm fairly certain that there's an issue with NTP.  Observations:

• Other D-Link products correctly obtain NTP information from 'time.chu.nrc.ca'
• The issue seems to be related with the handling of DST

[eladts]

I think that there are two reasons for the problem:

1. The router stores internally the time in the local format, while it should store it in UTC and only display the local format. This causes timestamps on NTFS volumes to be incorrect.

2. The timezone code displayed is determined using JavaScript from your browser instead of the router.

My workaround for (1) is to set the timezone to GMT/UTC and not use DST on the router. This way the timestamps on the shred disk are correct.

What D-Link should do is ALWAYS store the time in GMT/UTC and adjust the time displayed in the GUI using JavaScript. This way it won't be necessary to define time zone and DST dates at all.