Logging to stdout stops working after a couple of minutes
(this is the same as the stale issue #8955 but with a minimal reproducible example)
After running the pre-built docker-image version 10.0.5 with a few minor changes to records.yaml and logging.yaml ATS stops logging to stdout.
These are the two last lines from diags.log
[Apr 17 13:13:15.637] [ET_NET 7] NOTE: Traffic Server is fully initialized.
[Apr 17 13:18:35.441] [LOG_FLUSH] ERROR: Failed to write log to stdout: [tried 555, wrote 0, Bad file descriptor]
I've done some deeper testing and it seems ATS is restarting and after that logging fails (or, perhaps, logging fails so ATS restarts)
The only changes done in the attached files are
144c144
< server_ports: 8080 8080:ipv6
---
> server_ports: 8080
217c217
< pristine_host_hdr: 0
---
> pristine_host_hdr: 1
and
46,48c46,48
< - filename: squid
< format: squid
< mode: binary
---
> - filename: stdout
> format: common
> mode: ascii
This dockerfile does those changes, and nothing more.
FROM trafficserver/trafficserver:10.0.5
ADD logging.yaml /opt/etc/trafficserver/logging.yaml
ADD records.yaml /opt/etc/trafficserver/records.yaml
After building and starting a container logs appears on stdout for a couple if minutes, 5 in my case but I'm sure it can differ. I'm calling it periodically with watch, but any tool would be good
watch curl localhost:8080/hello/at/$(date +%s)
Below are the full records.yaml and logging.yaml
##############################################################################
# *NOTE*: All options covered in this file should be documented in the docs:
#
# https://docs.trafficserver.apache.org/en/latest/admin-guide/files/records.yaml.en.html
##############################################################################
records:
accept_threads: 1
cache:
limits:
http:
# https://docs.trafficserver.apache.org/en/latest/admin-guide/files/records.yaml.en.html#proxy-config-cache-limits-http-max-alts
max_alts: 5
log:
alternate:
# https://docs.trafficserver.apache.org/en/latest/admin-guide/files/records.yaml.en.html#proxy-config-cache-log-alternate-eviction
eviction: 0
# https://docs.trafficserver.apache.org/en/latest/admin-guide/files/records.yaml.en.html#proxy-config-cache-max-doc-size
max_doc_size: 0
min_average_object_size: 8000
##############################################################################
# RAM and disk cache configurations. Docs:
# https://docs.trafficserver.apache.org/en/latest/admin-guide/files/records.yaml.en.html#ram-cache
# https://docs.trafficserver.apache.org/en/latest/admin-guide/files/storage.config.en.html
##############################################################################
ram_cache:
size: -1
ram_cache_cutoff: 4194304
threads_per_disk: 8
##############################################################################
# Debugging. Docs:
# https://docs.trafficserver.apache.org/en/latest/admin-guide/files/records.yaml.en.html#diagnostic-logging-configuration
##############################################################################
diags:
debug:
enabled: 0
tags: http|dns
# https://docs.trafficserver.apache.org/en/latest/admin-guide/files/records.yaml.en.html#proxy-config-dump-mem-info-frequency
dump_mem_info_frequency: 0
##############################################################################
# Thread configurations. Docs:
# https://docs.trafficserver.apache.org/en/latest/admin-guide/files/records.yaml.en.html#thread-variables
##############################################################################
exec_thread:
affinity: 1
autoconfig:
enabled: 1
scale: 1.0
limit: 2
http:
accept_no_activity_timeout: 120
cache:
cache_responses_to_cookies: 1
cache_urls_that_look_dynamic: 1
##############################################################################
# Heuristic cache expiration. Docs:
# https://docs.trafficserver.apache.org/en/latest/admin-guide/files/records.yaml.en.html#heuristic-expiration
##############################################################################
heuristic_lm_factor: 0.1
heuristic_max_lifetime: 86400
heuristic_min_lifetime: 3600
##############################################################################
# Enable / disable HTTP caching. Useful for testing, but also as an
# overridable (per remap) config
##############################################################################
http: 1
##############################################################################
# Cache control. Docs:
# https://docs.trafficserver.apache.org/en/latest/admin-guide/files/records.yaml.en.html#cache-control
# https://docs.trafficserver.apache.org/en/latest/admin-guide/files/cache.config.en.html
##############################################################################
ignore_client_cc_max_age: 1
# https://docs.trafficserver.apache.org/en/latest/admin-guide/files/records.yaml.en.html#proxy-config-http-cache-required-headers
required_headers: 2
# https://docs.trafficserver.apache.org/en/latest/admin-guide/files/records.yaml.en.html#proxy-config-http-cache-when-to-revalidate
when_to_revalidate: 0
##############################################################################
# Origin server connect attempts. Docs:
# https://docs.trafficserver.apache.org/en/latest/admin-guide/files/records.yaml.en.html#origin-server-connect-attempts
##############################################################################
connect_attempts_max_retries: 3
connect_attempts_max_retries_down_server: 1
connect_attempts_rr_retries: 3
connect_attempts_timeout: 30
down_server:
cache_time: 60
forward:
proxy_auth_to_parent: 0
##############################################################################
# Proxy users variables. Docs:
# https://docs.trafficserver.apache.org/en/latest/admin-guide/files/records.yaml.en.html#proxy-user-variables
##############################################################################
insert_client_ip: 1
##############################################################################
# Via: headers. Docs:
# https://docs.trafficserver.apache.org/en/latest/admin-guide/files/records.yaml.en.html#proxy-config-http-insert-response-via-str
##############################################################################
insert_request_via_str: 1
insert_response_via_str: 0
insert_squid_x_forwarded_for: 1
keep_alive_no_activity_timeout_in: 120
keep_alive_no_activity_timeout_out: 120
##############################################################################
# Negative response caching, for redirects and errors. Docs:
# https://docs.trafficserver.apache.org/en/latest/admin-guide/files/records.yaml.en.html#negative-response-caching
##############################################################################
negative_caching_enabled: 0
negative_caching_lifetime: 1800
normalize_ae: 1
##############################################################################
# Parent proxy configuration, in addition to these settings also see parent.config. Docs:
# https://docs.trafficserver.apache.org/en/latest/admin-guide/files/records.yaml.en.html#parent-proxy-configuration
# https://docs.trafficserver.apache.org/en/latest/admin-guide/files/parent.config.en.html
##############################################################################
parent_proxy:
retry_time: 300
##############################################################################
# Security. Docs:
# https://docs.trafficserver.apache.org/en/latest/admin-guide/files/records.yaml.en.html#security
##############################################################################
push_method_enabled: 0
##############################################################################
# Specify server addresses and ports to bind for HTTP and HTTPS. Docs:
# https://docs.trafficserver.apache.org/en/latest/admin-guide/files/records.yaml.en.html#proxy.config.http.server_ports
##############################################################################
server_ports: 8080
# https://docs.trafficserver.apache.org/en/latest/admin-guide/files/records.yaml.en.html#proxy-config-http-slow-log-threshold
slow:
log:
threshold: 0
##############################################################################
# HTTP connection timeouts (secs). Docs:
# https://docs.trafficserver.apache.org/en/latest/admin-guide/files/records.yaml.en.html#http-connection-timeouts
##############################################################################
transaction_active_timeout_in: 900
transaction_active_timeout_out: 0
transaction_no_activity_timeout_in: 30
transaction_no_activity_timeout_out: 30
uncacheable_requests_bypass_parent: 1
##############################################################################
# Logging Config. Docs:
# https://docs.trafficserver.apache.org/en/latest/admin-guide/files/records.yaml.en.html#logging-configuration
# https://docs.trafficserver.apache.org/en/latest/admin-guide/files/logging.yaml.en.html
##############################################################################
log:
auto_delete_rolled_files: 1
logging_enabled: 3
max_space_mb_for_logs: 25000
max_space_mb_headroom: 1000
periodic_tasks_interval: 5
rolling_enabled: 1
rolling_interval_sec: 86400
rolling_size_mb: 10
##############################################################################
# Network. Docs:
# https://docs.trafficserver.apache.org/en/latest/admin-guide/files/records.yaml.en.html#network
##############################################################################
net:
connections_throttle: 30000
default_inactivity_timeout: 86400
max_connections_in: 30000
max_requests_in: 0
# https://docs.trafficserver.apache.org/en/latest/admin-guide/files/records.yaml.en.html#proxy-config-res-track-memory
res_track_memory: 0
# https://docs.trafficserver.apache.org/en/latest/admin-guide/files/records.yaml.en.html#reverse-proxy
reverse_proxy:
enabled: 1
ssl:
client:
CA:
cert:
filename: null
##############################################################################
# SSL Termination. Docs:
# https://docs.trafficserver.apache.org/en/latest/admin-guide/files/records.yaml.en.html#client-related-configuration
# https://docs.trafficserver.apache.org/en/latest/admin-guide/files/ssl_multicert.config.en.html
##############################################################################
verify:
server:
policy: PERMISSIVE
properties: ALL
task_threads: 2
##############################################################################
# These settings control remapping, and if the proxy allows (open) forward proxy or not. Docs:
# https://docs.trafficserver.apache.org/en/latest/admin-guide/files/records.yaml.en.html#url-remap-rules
# https://docs.trafficserver.apache.org/en/latest/admin-guide/files/remap.config.en.html
##############################################################################
url_remap:
# https://docs.trafficserver.apache.org/en/latest/admin-guide/files/records.yaml.en.html#proxy-config-url-remap-pristine-host-hdr
pristine_host_hdr: 1
remap_required: 1
acl_behavior_policy: 0
# Custom log configuration
#
# Documentation on logging:
# https://docs.trafficserver.apache.org/en/9.0.x/admin-guide/logging/index.en.html
#
# Documentation on logging.yaml file format:
# https://docs.trafficserver.apache.org/en/9.0.x/admin-guide/files/logging.yaml.en.html
#
# Example log configurations:
# https://docs.trafficserver.apache.org/en/9.0.x/admin-guide/logging/examples.en.html
logging:
formats:
# WebTrends Enhanced Log Format.
#
# The following is compatible with the WebTrends Enhanced Log Format.
# If you want to generate a log that can be parsed by WebTrends
# reporting tools, simply create a log that uses this format.
- name: welf
format: |-
id=firewall time="%<cqtd> %<cqtt>" fw=%<phn> pri=6 proto=%<pqus> duration=%<ttmsf> sent=%<psql> rcvd=%<cqhl> src=%<chi> dst=%<shi> dstname=%<shn> user=%<caun> op=%<cqhm> arg="%<pqup>" result=%<pssc> ref="%<{Referer}cqh>" agent="%<{user-agent}cqh>" cache=%<crc>
# Squid Log Format with seconds resolution timestamp.
# The following is the squid format but with a seconds-only timestamp
# (cqts) instead of a seconds and milliseconds timestamp (cqtq).
- name: squid_seconds_only_timestamp
format: '%<cqts> %<ttms> %<chi> %<crc>/%<pssc> %<psql> %<cqhm> %<pquc> %<caun> %<phr>/%<shn> %<psct>'
# Squid Log Format.
- name: squid
format: '%<cqtq> %<ttms> %<chi> %<crc>/%<pssc> %<psql> %<cqhm> %<pquc> %<caun> %<phr>/%<shn> %<psct>'
# Common Log Format.
- name: common
format: '%<chi> - %<caun> [%<cqtn>] "%<cqhm> %<pqu> %<cqpv>" %<pssc> %<pscl>'
# Extended Log Format.
- name: 'extended'
format: '%<chi> - %<caun> [%<cqtn>] "%<cqhm> %<pqu> %<cqpv>" %<pssc> %<pscl> %<sssc> %<sscl> %<cqcl> %<pqcl> %<cqhl> %<pshl> %<pqhl> %<sshl> %<tts>'
# Extended2 Log Formats
- name: "extended2"
format: '%<chi> - %<caun> [%<cqtn>] "%<cqhm> %<pqu> %<cqpv>" %<pssc> %<pscl> %<sssc> %<sscl> %<cqcl> %<pqcl> %<cqhl> %<pshl> %<pqhl> %<sshl> %<tts> %<phr> %<cfsc> %<pfsc> %<crc>'
logs:
- filename: stdout
format: common
mode: ascii
# vim: set ft=yaml :
In an attempt to work around this issue I've tried to pre-create a file that is a symlink to stdout of the first process
RUN ln -sF /proc/1/fd/1 /opt/var/log/trafficserver/output.log
RUN chown -h nobody:nogroup /opt/var/log/trafficserver/output.log
but it also fails.
Neither ascii nor ascii_pipe accepts that file and rotates it on startup
traffic_server WARNING: File /opt/var/log/trafficserver/output.log will be rolled because a LogObject with different format is requesting the same filename`
I've tried to read the source to understand what is required of my output.log for to not be rotated but my very poor c++-skills limits me and I can't find anything that I understand.
Is there any known way of doing something similar to this?
We are also hitting this issue - we ran bpftrace on the system and have seen ATS this:
ATS close(2)
__close_nocancel+11
fclose+273
BaseLogFile::close_file()+55
LogFile::close_file()+546
LogFile::check_fd()+117
Log::flush_thread_main(void*)+404
LoggingFlushContinuation::mainEvent(int, void*)+39
Continuation::handleEvent(int, void*)+235
EThread::execute()+105
spawn_thread_internal(void*)+129
0x71b9f9766aa4
0x71b9f97f3c3c
LogFile::check_fd
This routine will occasionally stat the current logfile to make sure that it really does exist. The easiest way to do this is to close the file and re-open it, which will create the file if it doesn't already exist.