[vz-users] Massive Probleme ... vzlogger läuft nicht mehr ...

Albert Dahmen albert.dahmen at gmail.com
Tue Jul 1 21:58:36 CEST 2014


Noch was interessantes:
Unter var/log/messages sehe ich, dass scheinbar der Speicher voll läuft ...
bis dann irgendwann nichts mehr geht ...

Folgender Block wiederholt sich jede Minute:

Jul  1 10:39:16 raspberrypi kernel: [391010.285681] apache2 invoked
oom-killer: gfp_mask=0x200da, order=0, oom_score_adj=0
Jul  1 10:39:16 raspberrypi kernel: [391010.285722] CPU: 0 PID: 12980 Comm:
apache2 Not tainted 3.12.20+ #687
Jul  1 10:39:16 raspberrypi kernel: [391010.285790] [<c0013ec0>]
(unwind_backtrace+0x0/0xf0) from [<c0011284>] (show_stack+0x10/0x14)
Jul  1 10:39:16 raspberrypi kernel: [391010.285824] [<c0011284>]
(show_stack+0x10/0x14) from [<c041d1c0>] (dump_header.isra.13+0x74/0x1b0)
Jul  1 10:39:16 raspberrypi kernel: [391010.285863] [<c041d1c0>]
(dump_header.isra.13+0x74/0x1b0) from [<c009d61c>]
(oom_kill_process+0x2b8/0x438)
Jul  1 10:39:16 raspberrypi kernel: [391010.285892] [<c009d61c>]
(oom_kill_process+0x2b8/0x438) from [<c009dc50>] (out_of_memory+0x27c/0x2c8)
Jul  1 10:39:16 raspberrypi kernel: [391010.285924] [<c009dc50>]
(out_of_memory+0x27c/0x2c8) from [<c00a1a8c>]
(__alloc_pages_nodemask+0x89c/0x8e0)
Jul  1 10:39:16 raspberrypi kernel: [391010.285954] [<c00a1a8c>]
(__alloc_pages_nodemask+0x89c/0x8e0) from [<c00bb2f0>]
(handle_mm_fault+0x764/0x9bc)
Jul  1 10:39:16 raspberrypi kernel: [391010.285998] [<c00bb2f0>]
(handle_mm_fault+0x764/0x9bc) from [<c0424e08>] (do_page_fault+0x240/0x3f0)
Jul  1 10:39:16 raspberrypi kernel: [391010.286027] [<c0424e08>]
(do_page_fault+0x240/0x3f0) from [<c000835c>] (do_DataAbort+0x34/0x98)
Jul  1 10:39:16 raspberrypi kernel: [391010.286054] [<c000835c>]
(do_DataAbort+0x34/0x98) from [<c042381c>] (__dabt_usr+0x3c/0x40)
Jul  1 10:39:16 raspberrypi kernel: [391010.286068] Exception
stack(0xc6e27fb0 to 0xc6e27ff8)
Jul  1 10:39:16 raspberrypi kernel: [391010.286085] 7fa0:
                  b842d298 b9451fe8 00000012 00000000
Jul  1 10:39:16 raspberrypi kernel: [391010.286139] 7fc0: 00000085 0003ce68
0000002a 0003cea0 b5a558e4 b9451fb0 00000000 be8752a0
Jul  1 10:39:16 raspberrypi kernel: [391010.286160] 7fe0: 00000011 be875210
b55d67f8 b55d5688 60000010 ffffffff
Jul  1 10:39:16 raspberrypi kernel: [391010.286172] Mem-info:
Jul  1 10:39:16 raspberrypi kernel: [391010.286182] Normal per-cpu:
Jul  1 10:39:16 raspberrypi kernel: [391010.286195] CPU    0: hi:  186,
btch:  31 usd:  59
Jul  1 10:39:16 raspberrypi kernel: [391010.286228] active_anon:51500
inactive_anon:51504 isolated_anon:0
Jul  1 10:39:16 raspberrypi kernel: [391010.286228]  active_file:182
inactive_file:219 isolated_file:0
Jul  1 10:39:16 raspberrypi kernel: [391010.286228]  unevictable:0
dirty:4294967190 writeback:154 unstable:0
Jul  1 10:39:16 raspberrypi kernel: [391010.286228]  free:2048
slab_reclaimable:314 slab_unreclaimable:1907
Jul  1 10:39:16 raspberrypi kernel: [391010.286228]  mapped:636 shmem:634
pagetables:1990 bounce:0
Jul  1 10:39:16 raspberrypi kernel: [391010.286228]  free_cma:122
Jul  1 10:39:16 raspberrypi kernel: [391010.286328] Normal free:8192kB
min:8192kB low:10240kB high:12288kB active_anon:206000kB
inactive_anon:206016kB active_file:728kB inactive_file:876kB
unevictable:0kB isolated(anon):0kB isolated(file):0kB present:458752kB
managed:447996kB mlocked:0kB dirty:4294966872kB writeback:616kB
mapped:2544kB shmem:2536kB slab_reclaimable:1256kB
slab_unreclaimable:7628kB kernel_stack:1096kB pagetables:7960kB
unstable:0kB bounce:0kB free_cma:488kB writeback_tmp:0kB
pages_scanned:25725 all_unreclaimable? yes
Jul  1 10:39:16 raspberrypi kernel: [391010.286348] lowmem_reserve[]: 0 0
Jul  1 10:39:16 raspberrypi kernel: [391010.301856] Normal: 376*4kB (UEMC)
36*8kB (MC) 2*16kB (RC) 1*32kB (R) 3*64kB (R) 2*128kB (R) 3*256kB (R)
0*512kB 1*1024kB (R) 0*2048kB 1*4096kB (R) = 8192kB
Jul  1 10:39:16 raspberrypi kernel: [391010.301929] 3927 total pagecache
pages
Jul  1 10:39:16 raspberrypi kernel: [391010.301948] 2892 pages in swap cache
Jul  1 10:39:16 raspberrypi kernel: [391010.301961] Swap cache stats: add
697662, delete 694770, find 278778/342138
Jul  1 10:39:16 raspberrypi kernel: [391010.301970] Free swap  = 0kB
Jul  1 10:39:16 raspberrypi kernel: [391010.301978] Total swap = 102396kB
Jul  1 10:39:16 raspberrypi kernel: [391010.513115] 114688 pages of RAM
Jul  1 10:39:16 raspberrypi kernel: [391010.513177] 2517 free pages
Jul  1 10:39:16 raspberrypi kernel: [391010.513189] 2689 reserved pages
Jul  1 10:39:16 raspberrypi kernel: [391010.513198] 1782 slab pages
Jul  1 10:39:16 raspberrypi kernel: [391010.520095] 19975 pages shared
Jul  1 10:39:16 raspberrypi kernel: [391010.520116] 2892 pages swap cached
Jul  1 10:39:16 raspberrypi kernel: [391010.520127] [ pid ]   uid  tgid
total_vm      rss nr_ptes swapents oom_score_adj name
Jul  1 10:39:16 raspberrypi kernel: [391010.520167] [  156]     0   156
 722        0       6      133         -1000 udevd
Jul  1 10:39:16 raspberrypi kernel: [391010.520186] [ 1559]     0  1559
 438       13       4       16         -1000 ifplugd
Jul  1 10:39:16 raspberrypi kernel: [391010.520204] [ 1581]     0  1581
 438       13       5       18         -1000 ifplugd
Jul  1 10:39:16 raspberrypi kernel: [391010.520223] [ 1885]     0  1885
7034       89       8       89             0 rsyslogd
Jul  1 10:39:16 raspberrypi kernel: [391010.520240] [ 1886] 65534  1886
 505        4       5       26             0 thd
Jul  1 10:39:16 raspberrypi kernel: [391010.520258] [ 1934]     0  1934
 18767      153      23      996             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.520275] [ 1971]     0  1971
3578       27       6       55             0 automount
Jul  1 10:39:16 raspberrypi kernel: [391010.520293] [ 1986]   104  1986
 795        0       5       56             0 dbus-daemon
Jul  1 10:39:16 raspberrypi kernel: [391010.520310] [ 2047]     0  2047
1094       23       6       33             0 cron
Jul  1 10:39:16 raspberrypi kernel: [391010.520327] [ 2503]     0  2503
 721        0       6      134         -1000 udevd
Jul  1 10:39:16 raspberrypi kernel: [391010.520346] [ 2510]     0  2510
 721        0       6      134         -1000 udevd
Jul  1 10:39:16 raspberrypi kernel: [391010.520391] [ 2533]  1000  2533
1709       24       8      137             0 s0vz
Jul  1 10:39:16 raspberrypi kernel: [391010.520412] [ 2567]   102  2567
1346       23       6       70             0 ntpd
Jul  1 10:39:16 raspberrypi kernel: [391010.520429] [ 2701]     0  2701
1554        0       6      106         -1000 sshd
Jul  1 10:39:16 raspberrypi kernel: [391010.520447] [ 2731]     0  2731
1074        0       5       32             0 getty
Jul  1 10:39:16 raspberrypi kernel: [391010.520464] [ 2732]     0  2732
1074        0       5       32             0 getty
Jul  1 10:39:16 raspberrypi kernel: [391010.520515] [ 2733]     0  2733
1074        0       5       32             0 getty
Jul  1 10:39:16 raspberrypi kernel: [391010.520538] [ 2734]     0  2734
1074        0       6       32             0 getty
Jul  1 10:39:16 raspberrypi kernel: [391010.520556] [ 2735]     0  2735
1074        0       6       32             0 getty
Jul  1 10:39:16 raspberrypi kernel: [391010.520574] [ 2736]     0  2736
1074        0       6       32             0 getty
Jul  1 10:39:16 raspberrypi kernel: [391010.520591] [ 2737]     0  2737
 517        0       5       31             0 getty
Jul  1 10:39:16 raspberrypi kernel: [391010.520614] [ 3024]     0  3024
1284        0       6       66             0 sudo
Jul  1 10:39:16 raspberrypi kernel: [391010.520659] [ 3025]     0  3025
 14551     3210      22      398             0 vzlogger
Jul  1 10:39:16 raspberrypi kernel: [391010.520682] [12729]    33 12729
 24007     3555      36     2287             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.520700] [12748]    33 12748
 23431     4116      35     1105             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.520720] [12755]    33 12755
 24071     4471      36     1375             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.520739] [12805]    33 12805
 23558     4214      35     1083             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.520757] [12808]    33 12808
 22532     2767      33     1537             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.520775] [12816]    33 12816
 23814     4486      35     1064             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.520793] [12846]    33 12846
 23300     4035      34      994             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.520811] [12864]    33 12864
 23364     4136      34      968             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.520829] [12865]    33 12865
 22599     2920      33     1466             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.520848] [12866]    33 12866
 23241     3839      34     1229             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.520866] [12887]    33 12887
 22601     3281      33     1009             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.520884] [12888]    33 12888
 24011     3126      35     2584             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.520902] [12906]    33 12906
 24139     3001      36     2840             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.520919] [12911]    33 12911
 24137     3008      36     2816             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.520938] [12930]    33 12930
 23561     4003      34     1243             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.520956] [12943]    33 12943
 24071     3949      36     1904             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.520974] [12946]    33 12946
 23496     3802      35     1432             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.520993] [12958]    33 12958
 24073     2958      35     2793             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521011] [12962]    33 12962
 24137     3309      36     2431             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521028] [12978]    33 12978
 24009     4892      35      808             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521046] [12980]    33 12980
 23753     4299      35     1130             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521065] [12981]    33 12981
 23049     3563      33     1148             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521082] [12982]    33 12982
 23113     3592      34     1214             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521101] [12983]    33 12983
 23049     3692      33     1062             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521119] [12985]    33 12985
 19878     1192      27      800             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521137] [12986]    33 12986
 19878     1198      27      809             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521154] [12987]    33 12987
 19878     1192      27      811             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521172] [12988]    33 12988
 19619     1059      26      858             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521190] [12989]    33 12989
 19619     1065      26      852             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521208] [12990]    33 12990
 19619     1082      26      835             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521227] [12992]    33 12992
 19878      999      27     1005             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521245] [12993]    33 12993
 19878     1064      27      928             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521264] [12994]    33 12994
 19878     1042      27      968             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521282] [12996]    33 12996
 19526      693      24      853             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521300] [12997]    33 12997
 19526      692      24      854             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521318] [12998]    33 12998
 19491      947      26      822             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521335] [13000]    33 13000
 19526      704      24      843             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521354] [13001]    33 13001
 19526      686      24      861             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521373] [13002]    33 13002
 19526      705      24      842             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521391] [13003]    33 13003
 19526      689      24      858             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521408] [13004]    33 13004
 19526      708      24      843             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521425] [13005]    33 13005
 19526      705      24      842             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521443] [13008]    33 13008
 19526      685      24      862             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521461] [13009]    33 13009
 19785      782      25      858             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521479] [13010]    33 13010
 19526      689      24      862             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521497] [13011]    33 13011
 19785      805      25      851             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521515] [13012]    33 13012
 19014      544      23      869             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521533] [13013]    33 13013
 18830      356      22      883             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521551] [13014]    33 13014
 19014      544      23      869             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521569] [13016]    33 13016
 19014      550      23      863             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521586] [13017]    33 13017
 19014      551      23      863             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521623] [13018]    33 13018
 19273      681      24      862             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521645] [13019]    33 13019
 19273      645      24      880             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521664] [13021]    33 13021
 19273      659      24      878             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521681] [13022]    33 13022
 19014      590      23      869             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521699] [13023]    33 13023
 19273      709      24      869             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521717] [13024]    33 13024
 19273      727      24      863             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521764] [13025]    33 13025
 19273      734      24      862             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521787] [13026]    33 13026
 18794      208      19      961             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521805] [13028]    33 13028
 18794      208      19      961             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521824] [13029]    33 13029
 18794      208      19      961             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521842] [13030]    33 13030
 18775      160      19      983             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521864] [13031]    33 13031
 18775      160      19      983             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521910] [13033]    33 13033
 18775      161      19      983             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521931] [13034]    33 13034
 18775      161      19      983             0 apache2
Jul  1 10:39:16 raspberrypi kernel: [391010.521950] [13035]    33 13035
 18775      161      19      983             0 apache2


Und dabei wird die Menge der laufenden apache2-Prozesse immer mehr. Und das
verbraucht dann wohl den Speicher (oder liege ich hier falsch).
Wodurch werden denn immer mehr dieser Prozesse gestartet?

Hier mal meine config von vzlogger:

/**
* vzlogger configuration
*
* use proper encoded JSON with javascript comments
*
* take a look at the wiki for detailed information:
* http://wiki.volkszaehler.org/software/controller/vzlogger#configuration
*/

{
"retry" : 30, /* how long to sleep between failed requests, in seconds */
"daemon": false, /* run periodically */
//"foreground" : true, /* dont run in background (prevents forking) */
"verbosity" : 1, /* between 0 and 15 */
"log" : "/var/log/vzlogger.log", /* path to logfile, optional */

"local" : {
"enabled" : false, /* should we start the local HTTPd for serving live
readings? */
"port" : 80, /* the TCP port for the local HTTPd */
"index" : true, /* should we provide a index listing of available channels
if no UUID was requested? */
"timeout" : 30, /* timeout for long polling comet requests, 0 disables
comet, in seconds */
"buffer" : 600 /* how long to buffer readings for the local interface, in
seconds */
},

"meters" : [{
         "enabled" : true, /* disabled meters will be ignored */
         "protocol" : "sml", /* see 'vzlogger -h' for list of available
prot$ */
         "device" : "/dev/ttyUSB0",
         "aggtime" : 2, // in sekunden (optional)
         "channels": [{
         "uuid" : "1beb67d0-ad01-11e3-999b-53238ad20771",
         "middleware" : "http://localhost/middleware.php",
         "aggmode" : "AVG", // Der Mittelwert für Leistung, "MAX" für
Zähler, "SUM" für Counter
         "identifier" : "1-0:16.7.0", /* Leistung */
         }, {
         "uuid" : "b5e94600-acf0-11e3-af91-0da9c0ff3a5a",
         "middleware" : "http://localhost/middleware.php",
         "aggmode" : "MAX", // Der Mittelwert für Leistung, "MAX" für
Zähler, "SUM" für Counter
         "identifier" : "1-0:1.8.0", /* Wirkarbeit Bezug +A */
         }, {
         "uuid" : "cf446ee0-acf0-11e3-8492-099774ca431a",
         "middleware" : "http://localhost/middleware.php",
         "aggmode" : "MAX", // Der Mittelwert für Leistung, "MAX" für
Zähler, "SUM" für Counter
         "identifier" : "1-0:2.8.0", /* Wirkarbeit Lieferung -A */
         }]
}
]}

Ist das soweit in Ordnung?
Ich habe nun auch aggmode eingestellt ... auf 2 Sekunden.
Aber wenn ich im Frontend mir die Daten ansehe, dann kommen aus meiner
Sicht immer noch mehrmals pro Sekunde neue Werte an.


Und noch zum Schluss: Wie komplex ist es denn, bei einem duplicate key den
Satz einfach zu verwerfen und nicht in die Datenbank zu schreiben ???

VG Albert


Am 1. Juli 2014 21:31 schrieb Thomas Gauweiler <thomas at gauweiler.org>:

>  Das hatte ich auch mal!
>
> Ich hatte den vzlogger mit aggtime : 600 ( = 10 Minuten) aber ohne echte
> Aggregation laufen, um die Last auf der Middleware zu reduzieren.
>
> Meine Theorie dazu:
> - Die middleware ist mal etwas langsamer als sonst.
> - vzlogger beendet den Request mit einem Timeout, die Middleware arbeitet
> aber noch und schreibt die Werte in die Datenbank.
> - vzlogger versucht das nächste Mal die alten Daten + die neuen Daten zu
> übertragen, dadurch dauert es noch länger. Und weil die Daten schon drin
> sind gibt es den Duplicate entry.
> - das Ganze schaukelt immer stärker auf.
>
> Meine Lösung: die aggtime auf 300 reduzieren. Seit dem keine Probleme mehr.
>
> Liebe Grüße, Thomas
>
> PS: es mehr als einen Thomas Gauweiler in dieser Mailingliste...
>
>
>
> Am 01.07.2014 19:18, schrieb Albert Dahmen:
>
> Heute hats mich wieder erwischt :-(
> Diesmal hat es den ganzen Pi runter gerissen :-((
>
>  Und wieder das gleiche Thema ...
>
>  Hier ein Auszug aus dem Log:
>
>  [Jul 01 06:41:51][chn0] CURL: Timeout was reached
> [Jul 01 06:41:51][chn1] CURL: Timeout was reached
> [Jul 01 06:41:51][chn2] CURL: Timeout was reached
> [Jul 01 06:42:21][chn0] CURL: Timeout was reached
> [Jul 01 06:42:21][chn2] CURL: Timeout was reached
> [Jul 01 06:42:21][chn1] CURL: Timeout was reached
> [Jul 01 06:42:24][chn2] CURL Error from middleware: 'DBALException': 'An
> exception occurred while executing 'INSERT INTO data (timestamp, value,
> channel_id) VALUES (?, ?, ?)' with params [1404189681166, 864750.3, 2]:
>
>  SQLSTATE[23000]: Integrity constraint violation: 1062 Duplicate entry
> '2-1404189681166'
> [Jul 01 06:42:24][chn1] CURL Error from middleware: 'DBALException': 'An
> exception occurred while executing 'INSERT INTO data (timestamp, value,
> channel_id) VALUES (?, ?, ?)' with params [1404189681166, 1030241.5, 1]:
>
>  SQLSTATE[23000]: Integrity constraint violation: 1062 Duplicate entry
> '1-1404189681166'
> [Jul 01 06:42:24][chn0] CURL Error from middleware: 'DBALException': 'An
> exception occurred while executing 'INSERT INTO data (timestamp, value,
> channel_id) VALUES (?, ?, ?)' with params [1404189681166, 342.2, 3]:
>
>  SQLSTATE[23000]: Integrity constraint violation: 1062 Duplicate entry
> '3-1404189681166' for
> [Jul 01 06:42:25][chn2] CURL Error from middleware: 'DBALException': 'An
> exception occurred while executing 'INSERT INTO data (timestamp, value,
> channel_id) VALUES (?, ?, ?)' with params [1404189681166, 864750.3, 2]:
>
>  SQLSTATE[23000]: Integrity constraint violation: 1062 Duplicate entry
> '2-1404189681166'
> [Jul 01 06:42:25][chn1] CURL Error from middleware: 'DBALException': 'An
> exception occurred while executing 'INSERT INTO data (timestamp, value,
> channel_id) VALUES (?, ?, ?)' with params [1404189681166, 1030241.5, 1]:
>
>  SQLSTATE[23000]: Integrity constraint violation: 1062 Duplicate entry
> '1-1404189681166'
> [Jul 01 06:42:25][chn0] CURL Error from middleware: 'DBALException': 'An
> exception occurred while executing 'INSERT INTO data (timestamp, value,
> channel_id) VALUES (?, ?, ?)' with params [1404189681166, 342.2, 3]:
>
>  SQLSTATE[23000]: Integrity constraint violation: 1062 Duplicate entry
> '3-1404189681166' for
> [Jul 01 06:42:27][chn0] CURL Error from middleware: 'DBALException': 'An
> exception occurred while executing 'INSERT INTO data (timestamp, value,
> channel_id) VALUES (?, ?, ?)' with params [1404189681166, 342.2, 3]:
>
>
>
>  Zuerst kommen die timeouts ... und dann tonnenweise Duplicate entries
> ... und scheinbar wird immer wieder der gleiche Satz in die Datenbank
> geschrieben ... und immer wieder der gleiche Fehler.
>
>  Dann geht es um 8:48 wie folgt weiter:
>
>  [Jul 01 08:48:17][chn2] CURL Error from middleware: 'DBALException': 'An
> exception occurred while executing 'INSERT INTO data (timestamp, value,
> channel_id) VALUES (?, ?, ?)' with params [1404189681166, 864750.3, 2]:
>
>  SQLSTATE[23000]: Integrity constraint violation: 1062 Duplicate entry
> '2-1404189681166'
> [Jul 01 08:48:23][chn0] CURL Error from middleware: 'DBALException': 'An
> exception occurred while executing 'INSERT INTO data (timestamp, value,
> channel_id) VALUES (?, ?, ?)' with params [1404189681166, 342.2, 3]:
>
>  SQLSTATE[23000]: Integrity constraint violation: 1062 Duplicate entry
> '3-1404189681166' for
> [Jul 01 08:48:29][chn1] CURL: Timeout was reached
> [Jul 01 08:48:48][chn2] CURL: Timeout was reached
> [Jul 01 08:48:53][chn0] CURL: Timeout was reached
> [Jul 01 08:49:00][chn1] CURL Error from middleware: 'DBALException': 'An
> exception occurred while executing 'INSERT INTO data (timestamp, value,
> channel_id) VALUES (?, ?, ?)' with params [1404189681166, 1030241.5, 1]:
>
>  SQLSTATE[23000]: Integrity constraint violation: 1062 Duplicate entry
> '1-1404189681166'
> [Jul 01 08:49:18][chn2] CURL: Timeout was reached
> [Jul 01 08:49:24][chn0] CURL: Timeout was reached
> [Jul 01 08:49:30][chn1] CURL: Timeout was reached
> [Jul 01 08:49:49][chn2] CURL: Timeout was reached
> [Jul 01 08:49:55][chn0] CURL: Timeout was reached
> [Jul 01 08:50:01][chn1] CURL: Timeout was reached
> [Jul 01 08:50:20][chn2] CURL: Timeout was reached
> [Jul 01 08:50:25][chn0] CURL: Timeout was reached
> [Jul 01 08:50:32][chn1] CURL: Timeout was reached
> [Jul 01 08:50:50][chn2] CURL: Timeout was reached
> [Jul 01 08:50:56][chn0] CURL: Timeout was reached
>
>
>  Das geht dann so weiter bis 10:39 ... da hat sich dann der ganze PI
> verabschiedet (zumindest kam ich nicht mehr per telnet auf den PI).
>
>  Nach einem Neustart sowie manuellem Start von vzlogger (da es ja als
> Service bei mir nicht mehr geht), läuft es nun wieder.
>
>  Irgendwie komme ich nicht weiter ...
>
>  VG Albert
>
>
>
> Am 30. Juni 2014 19:06 schrieb Albert Dahmen <albert.dahmen at gmail.com>:
>
>> Hallo Rainer,
>>
>>  nein, ein Muster finde ich nicht :-( Jetzt läuft es auch schon wieder
>> seit ein paar Tagen durch.
>> Mit WLAN kann es nicht zusammen hängen, da der PI direkt am Router hängt
>> und da auch direkt die Synology dran ist.
>>
>>  Per cron habe ich folgendes eingestellt:
>>
>> * 2 * * * /usr/bin/php /var/www/volkszaehler.org/misc/tools/aggregate.php
>> -m delta -l day aggregate
>>
>> 9 * * * * /usr/bin/php /var/www/volkszaehler.org/misc/tools/aggregate.php
>> -m delta -l hour aggregate
>>
>> 0 3 * * * /usr/bin/php /var/www/
>> volkszaehler.org/misc/tools/vzcompress2.php
>>
>> Vielleicht hängt es ja damit zusammen ...
>>
>>
>>  Die Fehler treten immer dann auf, wenn zuvor diverse Male der timeout
>> kommt. Also irgendwie steht das im Zusammenhang ...
>>
>> Aber warum der timeout kommt --> keine Ahnung. Eigentlich ist die
>> Synology 7x24 am Laufen ....
>>
>>
>>  Wenn man per config einstellen könnte, dass doppelte Sätze ignoriert
>> werden sollen (ignore_duplicates mit yes oder no), dann würde es sicher
>> helfen.
>>
>>
>>  VG Albert
>>
>>
>> Am 30. Juni 2014 14:27 schrieb Rainer Gauweiler <
>> volkszaehler at moppl.inka.de>:
>>
>>  Hallo Albert,
>>>
>>> Am 22.06.2014 11:18, schrieb Albert Dahmen:
>>>
>>>> (oom_kill_process+0x2b8/0x438) from [<c009dc50>]
>>>> (out_of_memory+0x27c/0x2c8)
>>>>
>>>
>>> Liest sich als würde Deinem System der Speicher ausgehen.
>>>
>>>
>>>  [Jun 22 00:57:50][chn0] CURL: Timeout was reached
>>>>
>>>
>>>  Da war Dein Webserver auf der synology nicht erreichbar.
>>>
>>>
>>>  [Jun 22 00:58:22][chn1] CURL Error from middleware: 'DBALException': 'An
>>>> exception occurred while executing 'INSERT INTO data (timestamp, value,
>>>> channel_id) VALUES (?, ?, ?)' with params [1403391440635, 951536.3, 1]:
>>>>
>>>> SQLSTATE[23000]: Integrity constraint violation: 1062 Duplicate entry
>>>> '1-1403391440635'
>>>>
>>>
>>>  Zu diesem Zeitstempel steht in diesem Channel schon etwas.
>>>
>>> Ich denke bei Dir passiert folgendes:
>>>
>>> a) Es tritt irgendeine race condition auf. Webserver nicht erreichbar,
>>> weil WLan nachts deaktiviert ist oder irgendwelche Aufräumprozesse laufen
>>> die den Webserver kurzfristig ab- und wieder anschalten
>>>
>>> b) vzlogger kommt aus dem Tritt und fängt sich nicht wieder
>>> c) vzlogger bekommt die Daten nicht los und speichert sie im
>>> Hauptspeicher - der ist irgendwann voll
>>>
>>> Inzwischen sind ja schon ein paar Tage vergangen - hast Du ein Muster
>>> gefunden?
>>>
>>> Gruss
>>>      Rainer
>>>
>>>
>>
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://demo.volkszaehler.org/pipermail/volkszaehler-users/attachments/20140701/e0df0496/attachment-0001.html>


More information about the volkszaehler-users mailing list