Пытаться понять что происходит в вашем коде по логам из нескольких контейнеров в docker-compose может быть плохой идеей, особено когда строчки логов выводятся в относительно случайном порядке. Что действительно происходит, по меньшей мере для docker-compose version 1.8.0, build 94f7016. Что можно легко проверить, запустив следующую команду несколько раз.
docker-compose logs|head
Вот мои примеры:
RUN 1
#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
#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'...
Как мы видим, кроме того, что вывод не одинаковый, строчки логов перемешаны по времени для разных контейнеров. И читать становится трудно.
Но есть решение, в linux есть для этого команда sort. Можно запомнить все аргументы и использовать их, а можно взять готовый shell скрипт.
Надеюсь, ваш ~/bin есть в вашем PATH, так что просто скачайте это в ~/bin, установите chmod a+x ~/bin/dcsl и наслаждайтесь.
Название – акроним от “Docker Compose Sorted Logs”, так что запоминайте. Использование простое и гибкое. Минус – не работает с режимом отслеживания на лету.
Использование:
#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 тут, комментарии и улучшения приветствуются: