Timestamp in log is always Thu Jan 1 01:00:00 1970

[OleLaursen]

I get log entries like this (log-date=true in the configuration) for a vassal:

[pid: 9789|app: 0|req: 82/234] 212.98.71.196 () {40 vars in 885 bytes} [Thu Jan 1 01:00:00 1970] GET /... => generated 229039 bytes in 180 msecs (HTTP/1.1 200) 6 headers in 209 bytes (3 switches on core 5)
[pid: 9789|app: 0|req: 83/235] 212.98.71.196 () {40 vars in 885 bytes} [Thu Jan 1 01:00:00 1970] GET /... => generated 1178484 bytes in 220 msecs (HTTP/1.1 200) 6 headers in 209 bytes (6 switches on core 6)
[pid: 9789|app: 0|req: 84/236] 157.55.39.5 () {40 vars in 578 bytes} [Thu Jan 1 01:00:00 1970] GET ... => generated 11830 bytes in 231 msecs (HTTP/1.1 404) 3 headers in 178 bytes (1 switches on core 2)

This is uwsgi 2.0.7 on Debian (kernel is 3.16.0-4-powerpc64) - it's a virtual machine running inside an IBM VIOS (AIX variant) which I suppose is a little bit odd, but everything else works fine, e.g. date returns the correct time, and similarly the nginx log has correct timestamps.

[unbit]

I can only suppose some kind of ctime_r() misbehaviour.

Can you try building a formatted log string with the fields described here:

http://uwsgi-docs.readthedocs.org/en/latest/LogFormat.html

and report which works and which returns epoch 0 ?

For example i would expect %(ctime) to fail and %(ltime) to succeed

[OleLaursen]

I tried ctime, ltime, epoch and time in one go:

ctime gives Thu Jan 1 01:00:00 1970
ltime gives 06/May/2015:12:04:17 +0200
epoch gives 1430906657
time gives 1430906657

By the way, looking at some logs from last year I can see that the timestamps were correct in uwsgi 1.2.3.

[unbit]

iirc in 1.2 we used ctime (non thread-safe) then we moved to ctime_r, maybe the issue is here