Trying to understand what’s happening inside your code running in multiple docker-compose containers by reading logs could be a terrible idea if log lines are outputted in a random manner. Which is true at least for docker-compose version 1.8.0, build 94f7016. This could be simply checked by running the following command several times.
1 | docker-compose logs|head |
Here are my examples:
RUN 1
1 2 3 4 5 6 7 8 9 10 11 | #docker-compose -f docker-compose-all.yml logs -t|head Attaching to oauth_web_1, oauth_core_1, oauth_core-ok_1, oauth_core-fb_1, oauth_oauth_1, oauth_fill-sqls-web_1, oauth_fill-sqls-oauth_1, oauth_web-redis_1, oauth_core-redis_1, oauth_core-mysql_1, oauth_oauth-mysql_1, oauth_web-mysql_1 core_1 | 2016-10-07T06:22:10.603699134Z [nodemon] 1.10.2 core_1 | 2016-10-07T06:22:10.604808539Z [nodemon] to restart at any time, enter `rs` core_1 | 2016-10-07T06:22:10.605207552Z [nodemon] watching: /usr/src/app/**/* core_1 | 2016-10-07T06:22:10.605788544Z [nodemon] starting `node --debug=3010 --max_old_space_size=4096 serverApi.js` core_1 | 2016-10-07T06:22:10.935801570Z Debugger listening on [::]:3010 core_1 | 2016-10-07T06:23:44.499687810Z :4443 core-ok_1 | 2016-10-07T06:22:03.932151348Z npm info it worked if it ends with ok core_1 | 2016-10-07T06:47:00.701059229Z core_1 | 2016-10-07T06:47:00.701097632Z --- mainParams [ { configuration: { domain: 'http://domain.example.dev/fb/authCode' } }, |
RUN 2
1 2 3 4 5 6 7 8 9 10 11 | #docker-compose -f docker-compose-all.yml logs -t|head Attaching to oauth_web_1, oauth_core_1, oauth_core-ok_1, oauth_core-fb_1, oauth_oauth_1, oauth_fill-sqls-web_1, oauth_fill-sqls-oauth_1, oauth_web-redis_1, oauth_core-redis_1, oauth_core-mysql_1, oauth_oauth-mysql_1, oauth_web-mysql_1 web_1 | 2016-10-07T06:23:26.013419543Z [06:23:26] Using gulpfile /usr/src/app/gulpfile.js web_1 | 2016-10-07T06:23:26.015218087Z [06:23:26] Starting 'run'... web_1 | 2016-10-07T06:23:26.016653267Z [06:23:26] Starting 'templates'... web_1 | 2016-10-07T06:23:26.026795066Z [06:23:26] Finished 'templates' after 9.26 ms web_1 | 2016-10-07T06:23:26.027174990Z [06:23:26] Starting 'scripts'... web_1 | 2016-10-07T06:23:26.040232845Z [06:23:26] Finished 'scripts' after 11 ms web_1 | 2016-10-07T06:23:26.040447720Z [06:23:26] Starting 'fonts'... web_1 | 2016-10-07T06:23:26.042183615Z [06:23:26] Finished 'fonts' after 1.31 ms web_1 | 2016-10-07T06:23:26.042293578Z [06:23:26] Starting 'images'... |
As we can see not only docker-compose logs command have logs line order non-persisting, it also mixes up times from different containers. Trying to understand what’s going on through these logs could be a task for a masochist.
But there’s a simple solution, linux has sort command for that. And while constantly typing in commands and their arguments might help learning them by heart it’s inconvenient for everyday tasks. So, why not have a prepared bash script for that.
I hope you have your ~/bin in your PATH, so simply download that to ~/bin folder, set chmod a+x ~/bin/dcsl and enjoy.
The name comes from “Docker Compose Sorted Logs”, so it’s easy to remember. The usage is simple, yet powerful. The downside is that doesn’t work with the follow logs mode.
Usage:
1 2 3 4 5 6 7 | #dcsl -h Input piped docker-compose logs -t, or a file created from this command, to show logs lines sorted by time. Usage: dcsl [-h|--help] - this message dcsl - runs default docker-compose logs -t and sorts'em docker-compose logs -t|dcsl - pipe logs to this command dcsl my-compose.log - or choose file with logs to display |
Gist is here, welcome to improve: