When running long-term bash scripts that output to log files, one critical piece of missing information is often the execution timestamp. Consider this common logging approach:
#!/bin/bash
while true; do
echo "Processing data batch..."
some_command >> /var/log/script_output.log
sleep 60
done
Without timestamps, troubleshooting becomes challenging when you need to correlate events with system logs or identify performance patterns.
Here are three robust methods to add timestamps, each with different advantages:
1. Using the date Command Directly
The simplest method uses command substitution:
#!/bin/bash
echo "$(date) - Starting script execution" >> /var/log/script_output.log
For more precise formatting (ISO 8601 standard):
echo "$(date +"%Y-%m-%dT%H:%M:%S%z") - Event occurred" >> /var/log/script_output.log
2. Creating a Logging Function
For reusable timestamped logging throughout your script:
#!/bin/bash
log() {
local timestamp=$(date +"%Y-%m-%d %H:%M:%S")
echo "[${timestamp}] $1" >> /var/log/script_output.log
}
log "Initializing components"
# Your script logic here
log "Process completed successfully"
3. Using exec and Process Substitution
For comprehensive timestamping of all output:
#!/bin/bash
exec > >(while read -r line; do
echo "$(date +"%F %T") $line" >> /var/log/script_output.log
done) 2>&1
echo "This line will be timestamped"
some_command
another_command
For production systems, consider these enhancements:
#!/bin/bash
LOG_FILE="/var/log/script_output.log"
MAX_LOG_SIZE=10485760 # 10MB
rotate_logs() {
if [ -f "$LOG_FILE" ]; then
local size=$(stat -c%s "$LOG_FILE")
if [ "$size" -gt "$MAX_LOG_SIZE" ]; then
mv "$LOG_FILE" "${LOG_FILE}.$(date +%Y%m%d%H%M%S)"
touch "$LOG_FILE"
fi
fi
}
log() {
rotate_logs
local timestamp=$(date +"%Y-%m-%d %H:%M:%S.%3N")
printf "[%s] %s\n" "$timestamp" "$1" >> "$LOG_FILE"
}
log "Script started with PID $$"
This implementation adds log rotation and millisecond precision timestamps.
For system-wide logging integration:
#!/bin/bash
log_system() {
logger -t "myscript[$$]" "$1"
}
log_system "This goes to syslog with automatic timestamps"
When running long-term bash scripts that output to log files, missing timestamps makes it nearly impossible to:
- Track when events occurred
- Calculate time between operations
- Correlate with other system logs
Your current approach:
script.sh >> /var/log/logfile
Produces ambiguous logs like:
The server has booted up. Hmmph.
Connection timeout occurred
Service restarted
Modify your script to include timestamps for each output line:
#!/bin/bash
echo "$(date '+%a %b %d %T %Z %Y') The server has booted up. Hmmph."
# Other commands...
This produces properly formatted output:
Sat Sep 10 21:33:06 UTC 2011 The server has booted up. Hmmph.
For cleaner code, create a logging function:
#!/bin/bash
log() {
echo "$(date '+%Y-%m-%d %H:%M:%S') $1" >> /var/log/logfile
}
log "Starting backup process"
# Your script commands...
log "Backup completed successfully"
For systems with moreutils installed:
script.sh | ts '%Y-%m-%d %H:%M:%S' >> /var/log/logfile
For high-frequency scripts:
echo "$(date '+%Y-%m-%d %H:%M:%S.%N') Event occurred"
Example output:
2023-11-15 14:22:31.548392100 Event occurred
When implementing timestamps, consider adding log rotation:
#!/bin/bash
LOG_FILE="/var/log/logfile_$(date +%Y-%m-%d).log"
log() {
echo "$(date '+%Y-%m-%d %H:%M:%S') $1" >> "$LOG_FILE"
}