Logging failed w/invalid system date, Davis Vantage Pro

EdBeavWX · Post by **EdBeavWX** » Mon May 13, 2013 5:09 am

Meteohub is not processing station data since the 4.9u update. After a reboot, it reads the log from the station, then starts complaining that the system date is not properly set, so logging can't start. The system date on System Info is correct.

Any help is appreciated.

Thanks,

Ed

BTW, My previous config had the serial Vantage plugged directly into the SheevaPlug via a TrendNet TU-S9 Serial-to-USB adapter. I have since tried connecting with a small unpowered USB hub between the TrendNet and the SheevaPlug.

System Info / Time

Code: Select all

UTC:	13.05.2013 02:54:10
Time Zone:	America/Vancouver
Local Time:	12.05.2013 19:54:10
Uptime:	18 hours, 40 minutes
System Load:	0.00, 0.03, 0.05

[/size]

There was nothing in the system log; I had cleared it a few days ago. Alarm log just had entries for "No data upload to weather networks as sensor selected on weather network page for outdoor temp, outdoor humidity or outdoor dewpoint is not providing recent data.:" and "No data upload to weather networks as sensor selected on weather network page for outdoor temp, outdoor humidity or outdoor dewpoint is not providing recent data.:"

meteohub log

Code: Select all

logger (09.05.2013 21:05:19): data logger (version 4.9u, build 1257) started.
logger (09.05.2013 21:05:20): connect station 0 (Vantage via USB serial).
logger (09.05.2013 21:05:20): connect station 1 (System Data via Plug-in).
logger (09.05.2013 21:05:21): station 0 (Vantage), wakeup sent.
logger (09.05.2013 21:05:21): station 0 (Vantage), internal logger activated.
logger (09.05.2013 21:05:21): station 0 (Vantage), syncing.
logger (09.05.2013 21:05:33): station 0 (Vantage), gettime request sent.
logger (09.05.2013 21:05:33): station 0 (Vantage), no Vantage time offset.
logger (09.05.2013 21:05:33): station 0 (Vantage), eeprom request sent.
logger (09.05.2013 21:05:33): station 0 (Vantage), rain collector size 0.01 inch per tick.
logger (09.05.2013 21:05:33): station 0 (Vantage), transmitter 1 active as station type (#0) "ISS".
logger (09.05.2013 21:05:33): station 0 (Vantage), firmware version request sent.
logger (09.05.2013 21:05:33): station 0 (Vantage), no firmware version returned.
logger (09.05.2013 21:05:33): station 0 (Vantage), data gap of 6952 minutes, start reading Vantage's internal logger after 2013-05-05 01:10 (Vantage's local time).
logger (09.05.2013 21:05:46): station 0 (Vantage), data gap of 6953 minutes, start reading Vantage's internal logger after 2013-05-05 01:10 (Vantage's local time).
<snip>
logger (09.05.2013 21:09:58): station 0 (Vantage), data gap of 6957 minutes, start reading Vantage's internal logger after 2013-05-05 01:10 (Vantage's local time).
wmr928fulleval(09.05.2013 21:10:01): recomputation of weather data started.
logger (09.05.2013 21:10:08): station 0 (Vantage), data gap of 6957 minutes, start reading Vantage's internal logger after 2013-05-05 01:10 (Vantage's local time).
<snip>logger (09.05.2013 21:43:11): station 0 (Vantage), data gap of 6990 minutes, start reading Vantage's internal logger after 2013-05-05 01:10 (Vantage's local time).
logger (09.05.2013 21:43:13): station 0 (Vantage), internal logger provides 513 pages of data.
logger (09.05.2013 21:44:30): station 0 (Vantage), finished reading internal logger, 162 records inserted.
logger (10.05.2013 01:13:12): parent process received termination signal (15).
logger (10.05.2013 01:13:12): child process received termination signal (15).
logger (31.12.1999 16:00:27): System date not properly set. Please set date and time correctly before data logging can start.
logger (31.12.1999 16:00:27): System date not properly set. Please set date and time correctly before data logging can start.
Timed out waiting for time change.
logger (31.12.1999 16:00:27): System date not properly set. Please set date and time correctly before data logging can start.
logger (31.12.1999 16:00:27): System date not properly set. Please set date and time correctly before data logging can start.[/size]

ntp client log

Code: Select all

10 May 01:14:32 ntpd[1263]: frequency initialized 14.707 PPM from /var/spool/ntp.drift
10 May 01:18:50 ntpd[1263]: synchronized to 50.97.210.169, stratum 2
10 May 01:18:50 ntpd[1263]: kernel time sync status change 0001
10 May 01:26:23 ntpd[1263]: synchronized to 216.45.57.38, stratum 2
10 May 02:53:30 ntpd[1263]: synchronized to 50.97.210.169, stratum 2
10 May 03:21:21 ntpd[1263]: synchronized to 216.45.57.38, stratum 2
10 May 03:28:52 ntpd[1263]: synchronized to 50.97.210.169, stratum 2
10 May 03:40:40 ntpd[1263]: synchronized to 216.45.57.38, stratum 2
10 May 04:41:35 ntpd[1263]: synchronized to 50.97.210.169, stratum 2
10 May 07:56:50 ntpd[1263]: synchronized to 216.45.57.38, stratum 2
10 May 08:40:55 ntpd[1263]: kernel time sync status change 4001
10 May 09:49:13 ntpd[1263]: kernel time sync status change 0001
10 May 10:57:31 ntpd[1263]: kernel time sync status change 4001
10 May 11:48:45 ntpd[1263]: kernel time sync status change 0001
10 May 12:22:54 ntpd[1263]: kernel time sync status change 4001
10 May 13:31:11 ntpd[1263]: kernel time sync status change 0001
10 May 14:05:20 ntpd[1263]: kernel time sync status change 4001
10 May 14:56:35 ntpd[1263]: kernel time sync status change 0001
10 May 16:04:52 ntpd[1263]: kernel time sync status change 4001
10 May 16:21:58 ntpd[1263]: kernel time sync status change 0001
10 May 17:13:11 ntpd[1263]: kernel time sync status change 4001
10 May 17:30:16 ntpd[1263]: kernel time sync status change 0001
10 May 18:21:29 ntpd[1263]: kernel time sync status change 4001
10 May 18:38:32 ntpd[1263]: kernel time sync status change 0001
10 May 19:29:47 ntpd[1263]: kernel time sync status change 4001
10 May 20:03:55 ntpd[1263]: kernel time sync status change 0001
11 May 01:14:26 ntpd[1264]: frequency initialized 24.994 PPM from /var/spool/ntp.drift
11 May 01:18:46 ntpd[1264]: synchronized to 76.103.90.196, stratum 2
11 May 01:18:46 ntpd[1264]: kernel time sync status change 0001
11 May 01:41:22 ntpd[1264]: synchronized to 69.65.40.29, stratum 2
11 May 01:58:34 ntpd[1264]: synchronized to 76.103.90.196, stratum 2
11 May 05:57:50 ntpd[1264]: kernel time sync status change 4001
11 May 06:31:51 ntpd[1264]: synchronized to 69.65.40.29, stratum 2
11 May 06:31:51 ntpd[1264]: kernel time sync status change 0001
11 May 07:23:06 ntpd[1264]: synchronized to 76.103.90.196, stratum 2
11 May 07:23:06 ntpd[1264]: kernel time sync status change 4001
11 May 07:40:17 ntpd[1264]: kernel time sync status change 0001
11 May 10:31:03 ntpd[1264]: kernel time sync status change 4001
11 May 11:05:11 ntpd[1264]: kernel time sync status change 0001
11 May 11:56:26 ntpd[1264]: kernel time sync status change 4001
11 May 12:13:30 ntpd[1264]: kernel time sync status change 0001
11 May 13:04:42 ntpd[1264]: kernel time sync status change 4001
11 May 13:21:45 ntpd[1264]: kernel time sync status change 0001
11 May 14:30:02 ntpd[1264]: kernel time sync status change 4001
11 May 15:21:20 ntpd[1264]: kernel time sync status change 0001
11 May 18:12:05 ntpd[1264]: kernel time sync status change 4001
11 May 18:12:24 ntpd[1264]: ntpd exiting on signal 15
11 May 18:13:36 ntpd[1275]: frequency initialized 25.217 PPM from /var/spool/ntp.drift
11 May 18:17:54 ntpd[1275]: synchronized to 198.55.111.50, stratum 2
11 May 18:17:54 ntpd[1275]: kernel time sync status change 0001
11 May 18:23:16 ntpd[1275]: synchronized to 199.4.29.166, stratum 2
11 May 18:53:25 ntpd[1275]: synchronized to 198.55.111.50, stratum 2
11 May 19:02:00 ntpd[1275]: synchronized to 199.4.29.166, stratum 2
11 May 19:15:49 ntpd[1275]: synchronized to 198.55.111.50, stratum 2
11 May 23:06:20 ntpd[1275]: kernel time sync status change 4001
12 May 01:14:24 ntpd[1275]: frequency initialized 24.887 PPM from /var/spool/ntp.drift
12 May 01:18:41 ntpd[1275]: synchronized to 97.107.128.165, stratum 3
12 May 01:18:41 ntpd[1275]: kernel time sync status change 0001
12 May 01:27:18 ntpd[1275]: synchronized to 50.116.55.65, stratum 2
12 May 05:55:29 ntpd[1275]: kernel time sync status change 4001
12 May 06:12:31 ntpd[1275]: kernel time sync status change 0001
12 May 07:20:51 ntpd[1275]: kernel time sync status change 4001
12 May 07:54:57 ntpd[1275]: kernel time sync status change 0001
12 May 08:29:07 ntpd[1275]: kernel time sync status change 4001
12 May 08:46:10 ntpd[1275]: kernel time sync status change 0001
12 May 10:45:38 ntpd[1275]: kernel time sync status change 4001
12 May 12:11:02 ntpd[1275]: kernel time sync status change 0001
12 May 13:36:22 ntpd[1275]: kernel time sync status change 4001
12 May 14:10:31 ntpd[1275]: kernel time sync status change 0001
12 May 15:18:48 ntpd[1275]: kernel time sync status change 4001
12 May 15:35:50 ntpd[1275]: kernel time sync status change 0001
12 May 16:10:02 ntpd[1275]: kernel time sync status change 4001
12 May 16:44:10 ntpd[1275]: kernel time sync status change 0001
12 May 17:18:20 ntpd[1275]: kernel time sync status change 4001
12 May 17:52:26 ntpd[1275]: kernel time sync status change 0001
12 May 18:43:39 ntpd[1275]: kernel time sync status change 4001
12 May 19:00:45 ntpd[1275]: kernel time sync status change 0001
12 May 19:34:58 ntpd[1275]: kernel time sync status change 4001

[/size]

dmesg log

Code: Select all

DMESG:
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpu
[    0.000000] Linux version 2.6.32-5-kirkwood (Debian 2.6.32-13) (maks@debian.org) (gcc version 4.3.4 (Debian 4.3.4-10) ) #1 Fri May 21 05:44:29 UTC 2010
[    0.000000] CPU: Feroceon 88FR131 [56251311] revision 1 (ARMv5TE), cr=00053177
[    0.000000] CPU: VIVT data cache, VIVT instruction cache
[    0.000000] Machine: Marvell SheevaPlug Reference Board
[    0.000000] Memory policy: ECC disabled, Data cache writeback
[    0.000000] On node 0 totalpages: 131072
[    0.000000] free_area_init_node: node 0, pgdat c03db168, node_mem_map c0cfa000
[    0.000000]   Normal zone: 1024 pages used for memmap
[    0.000000]   Normal zone: 0 pages reserved
[    0.000000]   Normal zone: 130048 pages, LIFO batch:31
[    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 130048
[    0.000000] Kernel command line: console=ttyS0,115200 mtdparts=nand_mtd:0xc0000@0(uboot)ro,0x1ff00000@0x100000(root) root=/dev/mmcblk0p1 rootdelay=10
[    0.000000] PID hash table entries: 2048 (order: 1, 8192 bytes)
[    0.000000] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes)
[    0.000000] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes)
[    0.000000] Memory: 256MB 256MB = 512MB total
[    0.000000] Memory: 509952KB available (3548K code, 583K data, 120K init, 0K highmem)
[    0.000000] SLUB: Genslabs=11, HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[    0.000000] Hierarchical RCU implementation.
[    0.000000] NR_IRQS:114
[    0.000000] Console: colour dummy device 80x30
[   21.474967] Calibrating delay loop... 1192.75 BogoMIPS (lpj=5963776)
[   21.714926] Security Framework initialized
[   21.714945] SELinux:  Disabled at boot.
[   21.714974] Mount-cache hash table entries: 512
[   21.715273] Initializing cgroup subsys ns
[   21.715289] Initializing cgroup subsys cpuacct
[   21.715299] Initializing cgroup subsys devices
[   21.715308] Initializing cgroup subsys freezer
[   21.715316] Initializing cgroup subsys net_cls
[   21.715361] CPU: Testing write buffer coherency: ok
[   21.716084] devtmpfs: initialized
[   21.717946] regulator: core version 0.5
[   21.718162] NET: Registered protocol family 16
[   21.718685] Kirkwood: MV88F6281-A1, TCLK=200000000.
[   21.718698] Feroceon L2: Enabling L2
[   21.718731] Feroceon L2: Cache support initialised.
[   21.719164] initial MPP regs: 01111111 11113322 00001111 00100000 00000000 00000000 00000000
[   21.719186]   final MPP regs: 01111111 11113322 00001111 00000000 00000000 00000000 00000000
[   21.720813] bio: create slab <bio-0> at 0
[   21.721085] vgaarb: loaded
[   21.721553] Switching to clocksource orion_clocksource
[   21.725362] NET: Registered protocol family 2
[   21.725609] IP route cache hash table entries: 4096 (order: 2, 16384 bytes)
[   21.726415] TCP established hash table entries: 16384 (order: 5, 131072 bytes)
[   21.726770] TCP bind hash table entries: 16384 (order: 4, 65536 bytes)
[   21.726950] TCP: Hash tables configured (established 16384 bind 16384)
[   21.726959] TCP reno registered
[   21.727114] NET: Registered protocol family 1
[   21.727287] Unpacking initramfs...
[   22.059756] Freeing initrd memory: 5092K
[   22.059852] NetWinder Floating Point Emulator V0.97 (double precision)
[   22.060105] audit: initializing netlink socket (disabled)
[   22.060139] type=2000 audit(0.570:1): initialized
[   22.066898] VFS: Disk quotas dquot_6.5.2
[   22.067170] Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[   22.067265] JFFS2 version 2.2. (NAND) (SUMMARY)  © 2001-2006 Red Hat, Inc.
[   22.067908] msgmni has been set to 1006
[   22.069605] alg: No test for stdrng (krng)
[   22.069725] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 253)
[   22.069738] io scheduler noop registered
[   22.069745] io scheduler anticipatory registered
[   22.069753] io scheduler deadline registered
[   22.069945] io scheduler cfq registered (default)
[   22.076133] Serial: 8250/16550 driver, 2 ports, IRQ sharing disabled
[   22.076601] serial8250.0: ttyS0 at MMIO 0xf1012000 (irq = 33) is a 16550A
[   22.404031] console [ttyS0] enabled
[   22.408096] NAND device: Manufacturer ID: 0xec, Chip ID: 0xdc (Samsung NAND 512MiB 3,3V 8-bit)
[   22.416792] Scanning device for bad blocks
[   22.431456] Bad eraseblock 283 at 0x000002360000
[   22.445227] Bad eraseblock 529 at 0x000004220000
[   22.450493] Bad eraseblock 546 at 0x000004440000
[   22.586725] Creating 3 MTD partitions on "orion_nand":
[   22.591903] 0x000000000000-0x000000100000 : "u-boot"
[   22.597458] 0x000000100000-0x000000500000 : "uImage"
[   22.602944] 0x000000500000-0x000020000000 : "root"
[   22.609237] mice: PS/2 mouse device common for all mice
[   22.614866] rtc-mv rtc-mv: rtc core: registered rtc-mv as rtc0
[   22.620792] i2c /dev entries driver
[   22.624512] cpuidle: using governor ladder
[   22.628748] cpuidle: using governor menu
[   22.632799] Registered led device: plug:green:health
[   22.637837] mv_xor_shared mv_xor_shared.0: Marvell shared XOR driver
[   22.644254] mv_xor_shared mv_xor_shared.1: Marvell shared XOR driver
[   22.681620] mv_xor mv_xor.0: Marvell XOR: ( xor cpy )
[   22.721619] mv_xor mv_xor.1: Marvell XOR: ( xor fill cpy )
[   22.761616] mv_xor mv_xor.2: Marvell XOR: ( xor cpy )
[   22.801617] mv_xor mv_xor.3: Marvell XOR: ( xor fill cpy )
[   22.808349] TCP cubic registered
[   22.811614] NET: Registered protocol family 17
[   22.816090] Gating clock of unused units
[   22.816098] before: 0x00dfc3dd
[   22.816106]  after: 0x00c701d9
[   22.816411] registered taskstats version 1
[   22.821197] rtc-mv rtc-mv: setting system clock to 2000-01-01 00:00:00 UTC (946684800)
[   22.829175] Initalizing network drop monitor service
[   22.834231] Freeing init memory: 120K
[   23.210228] mmc0: mvsdio driver initialized, lacking card detect (fall back to polling)
[   23.289490] mmc0: host does not support reading read-only switch. assuming write-enable.
[   23.304378] mmc0: new high speed SDHC card at address b368
[   24.164144] usbcore: registered new interface driver usbfs
[   24.191114] mmcblk0: mmc0:b368 SDC   3.84 GiB 
[   24.195765] usbcore: registered new interface driver hub
[   24.203685]  mmcblk0:
[   24.206039] usbcore: registered new device driver usb
[   24.212208]  p1 p2 p3
[   24.216027] MV-643xx 10/100/1000 ethernet driver version 1.4
[   24.262283] mv643xx_eth smi: probed
[   24.284957] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[   24.340490] net eth0: port 0 with MAC address f0:ad:4e:00:09:c2
[   24.346531] orion-ehci orion-ehci.0: Marvell Orion EHCI
[   24.358916] orion-ehci orion-ehci.0: new USB bus registered, assigned bus number 1
[   24.421691] orion-ehci orion-ehci.0: irq 19, io mem 0xf1050000
[   24.441593] orion-ehci orion-ehci.0: USB 2.0 started, EHCI 1.00
[   24.447598] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[   24.454440] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[   24.461709] usb usb1: Product: Marvell Orion EHCI
[   24.466433] usb usb1: Manufacturer: Linux 2.6.32-5-kirkwood ehci_hcd
[   24.472832] usb usb1: SerialNumber: orion-ehci.0
[   24.478356] usb usb1: configuration #1 chosen from 1 choice
[   24.484559] hub 1-0:1.0: USB hub found
[   24.488359] hub 1-0:1.0: 1 port detected
[   24.811600] usb 1-1: new high speed USB device using orion-ehci and address 2
[   24.962965] usb 1-1: New USB device found, idVendor=05e3, idProduct=0608
[   24.969700] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0
[   24.976881] usb 1-1: Product: USB2.0 Hub
[   24.981991] usb 1-1: configuration #1 chosen from 1 choice
[   24.991776] hub 1-1:1.0: USB hub found
[   25.001640] hub 1-1:1.0: 4 ports detected
[   25.291877] usb 1-1.2: new full speed USB device using orion-ehci and address 3
[   25.402838] usb 1-1.2: New USB device found, idVendor=067b, idProduct=2303
[   25.409746] usb 1-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[   25.417101] usb 1-1.2: Product: USB-Serial Controller D
[   25.422390] usb 1-1.2: Manufacturer: Prolific Technology Inc. 
[   25.429340] usb 1-1.2: configuration #1 chosen from 1 choice
[   34.669566] md: linear personality registered for level -1
[   34.701153] md: multipath personality registered for level -4
[   34.733173] md: raid0 personality registered for level 0
[   34.771752] md: raid1 personality registered for level 1
[   34.801400] async_tx: api initialized (async)
[   34.816570] xor: measuring software checksum speed
[   34.861580]    arm4regs  :  1084.800 MB/sec
[   34.911579]    8regs     :   804.000 MB/sec
[   34.961577]    32regs    :   891.200 MB/sec
[   34.965775] xor: using function: arm4regs (1084.800 MB/sec)
[   35.151872] raid6: int32x1     76 MB/s
[   35.321766] raid6: int32x2    102 MB/s
[   35.491704] raid6: int32x4    123 MB/s
[   35.661984] raid6: int32x8    109 MB/s
[   35.665747] raid6: using algorithm int32x4 (123 MB/s)
[   35.705017] md: raid6 personality registered for level 6
[   35.710357] md: raid5 personality registered for level 5
[   35.715735] md: raid4 personality registered for level 4
[   35.851686] md: raid10 personality registered for level 10
[   35.937576] end_request: I/O error, dev mtdblock0, sector 0
[   35.943185] Buffer I/O error on device mtdblock0, logical block 0
[   35.949471] uncorrectable error : 
[   35.952727] uncorrectable error : 
[   35.956150] end_request: I/O error, dev mtdblock0, sector 8
[   35.961932] Buffer I/O error on device mtdblock0, logical block 1
[   35.968182] uncorrectable error : 
[   35.971424] uncorrectable error : 
[   35.974856] end_request: I/O error, dev mtdblock0, sector 16
[   35.980723] Buffer I/O error on device mtdblock0, logical block 2
[   35.986972] uncorrectable error : 
[   35.990219] end_request: I/O error, dev mtdblock0, sector 24
[   35.996087] Buffer I/O error on device mtdblock0, logical block 3
[   36.002471] end_request: I/O error, dev mtdblock0, sector 0
[   36.008069] Buffer I/O error on device mtdblock0, logical block 0
[   36.063517] end_request: I/O error, dev mtdblock0, sector 0
[   36.069119] Buffer I/O error on device mtdblock0, logical block 0
[   36.075405] uncorrectable error : 
[   36.078645] uncorrectable error : 
[   36.082081] end_request: I/O error, dev mtdblock0, sector 8
[   36.087866] Buffer I/O error on device mtdblock0, logical block 1
[   36.094117] uncorrectable error : 
[   36.097359] uncorrectable error : 
[   36.100780] end_request: I/O error, dev mtdblock0, sector 16
[   36.106648] Buffer I/O error on device mtdblock0, logical block 2
[   36.113014] uncorrectable error : 
[   36.116259] end_request: I/O error, dev mtdblock0, sector 24
[   36.122126] Buffer I/O error on device mtdblock0, logical block 3
[   36.128403] end_request: I/O error, dev mtdblock0, sector 0
[   36.134003] Buffer I/O error on device mtdblock0, logical block 0
[   36.223378] kjournald starting.  Commit interval 5 seconds
[   36.228913] EXT3-fs: mounted filesystem with ordered data mode.
[   37.452435] udevd version 125 started
[   39.677593] usbcore: registered new interface driver usbserial
[   39.690174] USB Serial support registered for generic
[   39.698331] usbcore: registered new interface driver usbserial_generic
[   39.704945] usbserial: USB Serial Driver core
[   39.724197] USB Serial support registered for pl2303
[   39.734093] pl2303 1-1.2:1.0: pl2303 converter detected
[   39.742325] usb 1-1.2: pl2303 converter now attached to ttyUSB0
[   39.748404] usbcore: registered new interface driver pl2303
[   39.754068] pl2303: Prolific PL2303 USB to serial adaptor driver
[   41.804344] Adding 134532k swap on /dev/mmcblk0p2.  Priority:-1 extents:1 across:134532k SS
[   41.927307] EXT3 FS on mmcblk0p1, internal journal
[   44.369032] loop: module loaded
[   44.663168] end_request: I/O error, dev mtdblock0, sector 0
[   44.668776] Buffer I/O error on device mtdblock0, logical block 0
[   44.675092] uncorrectable error : 
[   44.678338] uncorrectable error : 
[   44.681775] end_request: I/O error, dev mtdblock0, sector 8
[   44.687558] Buffer I/O error on device mtdblock0, logical block 1
[   44.693810] uncorrectable error : 
[   44.697051] uncorrectable error : 
[   44.700472] end_request: I/O error, dev mtdblock0, sector 16
[   44.706341] Buffer I/O error on device mtdblock0, logical block 2
[   44.712712] uncorrectable error : 
[   44.715959] end_request: I/O error, dev mtdblock0, sector 24
[   44.721827] Buffer I/O error on device mtdblock0, logical block 3
[   44.728104] end_request: I/O error, dev mtdblock0, sector 0
[   44.733703] Buffer I/O error on device mtdblock0, logical block 0
[   45.115292] kjournald starting.  Commit interval 120 seconds
[   45.123713] EXT3 FS on mmcblk0p3, internal journal
[   45.128540] EXT3-fs: mounted filesystem with ordered data mode.
[   46.762720] NET: Registered protocol family 10
[   46.768737] lo: Disabled Privacy Extensions
[   46.788959] ADDRCONF(NETDEV_UP): eth0: link is not ready
[   48.788820] eth0: link up, 1000 Mb/s, full duplex, flow control disabled
[   48.795747] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[   48.989462] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[   56.559371] warning: `ntpd' uses 32-bit capabilities (legacy support in use)
[   59.431532] eth0: no IPv6 routers present

USB:
Bus 001 Device 003: ID 067b:2303 Prolific Technology, Inc. PL2303 Serial Port
Bus 001 Device 002: ID 05e3:0608 Genesys Logic, Inc. USB-2.0 4-Port HUB
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

PCI:


Partitions:
Filesystem           1K-blocks      Used Available Use% Mounted on
/dev/mmcblk0p1          858832    680576    134640  84% /
tmpfs                   257768         0    257768   0% /lib/init/rw
udev                     10240       464      9776   5% /dev
tmpfs                   257768         0    257768   0% /dev/shm
/dev/mmcblk0p3         2603128   1397520   1073376  57% /data
tmpfs                     8192         0      8192   0% /var/lock
tmpfs                    32768      1820     30948   6% /var/run
tmpfs                    32768        16     32752   1% /var/log

Process:
  PID TTY      STAT   TIME COMMAND
    1 ?        Ss     0:01 init [2]  
    2 ?        S      0:00 [kthreadd]
    3 ?        S      0:00 [ksoftirqd/0]
    4 ?        S      0:00 [watchdog/0]
    5 ?        S      0:00 [events/0]
    6 ?        S      0:00 [cpuset]
    7 ?        S      0:00 [khelper]
    8 ?        S      0:00 [netns]
    9 ?        S      0:00 [async/mgr]
   10 ?        S      0:00 [pm]
   11 ?        S      0:00 [sync_supers]
   12 ?        S      0:00 [bdi-default]
   13 ?        S      0:00 [kintegrityd/0]
   14 ?        S      0:00 [kblockd/0]
   15 ?        S      0:00 [kseriod]
   16 ?        S      0:00 [khungtaskd]
   17 ?        S      0:00 [kswapd0]
   18 ?        SN     0:00 [ksmd]
   19 ?        S      0:00 [aio/0]
   20 ?        S      0:00 [crypto/0]
   25 ?        S      0:00 [mtdblockd]
   26 ?        S      0:00 [orion_spi]
   27 ?        S      0:00 [kpsmoused]
   64 ?        S      0:00 [kmmcd]
  256 ?        S      0:00 [ksuspend_usbd]
  260 ?        S      0:09 [mmcqd]
  262 ?        S      0:00 [khubd]
  371 ?        S      0:01 [kjournald]
  458 ?        S<s    0:00 udevd --daemon
  703 ?        S      0:00 [mv_crypto]
  767 ?        Ss     0:02 logsave -s /var/log/fsck/checkroot fsck -C -y -t ext3 /dev/mmcblk0p1
  885 ?        Ss     0:02 logsave -s /var/log/fsck/checkfs fsck -C -R -A -y
  894 ?        S      0:00 [kjournald]
  990 ?        Ss     0:00 /sbin/portmap
 1002 ?        Ss     0:00 /sbin/rpc.statd
 1004 ?        S      0:00 [flush-179:0]
 1141 ?        S      0:00 /home/meteohub/meteoschedule /dev/meteohub
 1170 ?        Sl     3:18 /usr/sbin/rsyslogd -f /etc/syslog.conf
 1186 ?        Ss     0:00 /usr/bin/dbus-daemon --system
 1200 ?        Ss     0:00 /usr/sbin/sshd
 1227 ?        S      0:08 /home/meteohub/meteonet -r
 1248 ?        Ss     0:00 /usr/bin/rsync /var/run/rsyncd.pid --daemon
 1253 ?        Ss     0:00 /usr/sbin/nmbd -D
 1255 ?        Ss     0:00 /usr/sbin/smbd -D
 1271 ?        S      0:00 /usr/sbin/smbd -D
 1275 ?        Ss     0:00 /usr/sbin/ntpd -p /var/run/ntpd.pid -u 105:107 -g
 1285 ?        Ss     0:00 /sbin/mdadm --monitor --pid-file /var/run/mdadm/monitor.pid --daemonise --scan --syslog
 1305 ?        Ss     0:02 /usr/sbin/cron
 1315 ?        SLs    0:02 /usr/sbin/watchdog
 1328 ttyS0    Ss+    0:00 /sbin/getty -L ttyS0 115200 linux
 2850 ?        S<s    0:00 /usr/sbin/thttpd -C /etc/thttpd.conf
 2852 ?        S<s    0:00 /usr/sbin/thttpdbackup -C /etc/thttpd-backup.conf
10068 ?        Z      0:00 [watchdog] <defunct>
10069 ?        S<     0:00 meteohub.cgi
10070 ?        Z<     0:00 [thttpd] <defunct>
10071 ?        S<     0:00 /usr/sbin/thttpd -C /etc/thttpd.conf
10103 ?        R<     0:00 ps ax

[/size]

Post by **admin** » Tue May 14, 2013 10:29 pm

The rapid change in system time is causing you trouble.
Please do not select using "weather station RF clock" (I dont know how it is phrased exactly)
on "Settings" page. This might cause the strange clock change.

EdBeavWX · Post by **EdBeavWX** » Wed May 15, 2013 7:42 am

> Please do not select using "weather station RF clock" (I dont know how it is phrased exactly)
Do you mean "Radio Clock" ?

Mine is sent to "not used" See attached.

Thanks,

Ed

Post by **admin** » Wed May 15, 2013 8:53 am

Could you please browse to "http://lan-ip-of-your-meteohub/cgi-bin/help.cgi"?
This might allow me to login to your Meteohub and to have a look there.

EdBeavWX · Post by **EdBeavWX** » Thu May 16, 2013 7:06 am

I tried setting "Radio Clock" to "Station-1: System Data (WeatherPlug)". This didn't seem to work, so I set it back to "not used'. All of a sudden (after a long period to recalculate weather data), it started logging, and I'm back up and running.

I did see occasional "No data upload to weather networks as sensor selected on weather network page for outdoor temp, outdoor humidity or outdoor dewpoint is not providing recent data.:" in the alarm log. Also one "datalog: Logging of Weather Data aborted". This isn't normal for my system in my experience.

In the system log I'm seeing some log entries with dates around the Unix Epoch, i.e. 1999. I don't know if these were logged before or after I changed "Radio Clock".

I would appreciate it if you could connect and check out my system. I went ahead and opened & port forwarded ports 22 and 7777 to the SheevaPlug and ran the script to open the ssh tunnel for support. Thanks so much for all your help.

Ed

Post by **admin** » Thu May 16, 2013 2:36 pm

Sorry, ssh script did not open a tunnel. Could you please mail the WAN IP of your router to "info(at)meteohub.de",
that should allow me to login, when you did setup forwarding of ports 22 and 7777 to your Meteohub.

EdBeavWX · Post by **EdBeavWX** » Thu May 16, 2013 3:33 pm

BTW, logging stopped overnight. I didn't have a chance to look at any detail, but it appears to have stopped after the daily overnight reboot.

WAN IP sent.

Ed

EdBeavWX · Post by **EdBeavWX** » Tue May 28, 2013 5:20 am

Boris has connected to my system and it looks like he has this figured out. He said "root cause for the "halted data logging" problem after reboot is that your sheevaplug does loose date/time from hw clock (most probably worn out battery). Result is,
that data logging does stop because date/time is obviously wrong and therefore data logging is not making sense." The reason it worked sometimes and not others is that the NTP deamon would reset the system clock to the correct time based on the time it got from the Internet. One big symptom was in the system log. Some of the times that were logged were correct (in 2013) and others incorrect (in 1999).

I'll be replacing the real-time clock (RTC) battery this week, and will report back if this is indeed the correct diagnosis.

Thanks again to Boris for his outstanding support!

Ed

meteohub.de

Logging failed w/invalid system date, Davis Vantage Pro

Logging failed w/invalid system date, Davis Vantage Pro

Re: Logging failed w/invalid system date, Davis Vantage Pro

Re: Logging failed w/invalid system date, Davis Vantage Pro

Re: Logging failed w/invalid system date, Davis Vantage Pro

Re: Logging failed w/invalid system date, Davis Vantage Pro

Re: Logging failed w/invalid system date, Davis Vantage Pro

Re: Logging failed w/invalid system date, Davis Vantage Pro

Re: Logging failed w/invalid system date, Davis Vantage Pro