Skip to content

Somehow duct negatively affects running the bash script (grep or pipe) #261

Description

@yarikoptic

trying to process s3 logs for dandi and thought to use duct, but it causes the goaccess to error out as if there were no input from grep. It is very odd

Here is without duct

dandi@drogon:/mnt/backup/dandi/dandiarchive-logs-goaccess-logs$ bash -x code/process_log ../dandiarchive-logs/2025/01/01.log
+ set -eu
+ logs_topdir=/mnt/backup/dandi/dandiarchive-logs
++ dirname code/process_log
+ topdir=code/..
+ force=
+ for in_log in "$@"
++ sed -E 's#.*/([0-9]{4}/[0-9]{2}(/[0-9]{2})?).*#\1#'
++ echo ../dandiarchive-logs/2025/01/01.log
+ log_date=2025/01/01
+ o_log=code/../2025/01/01.html
+ '[' -e code/../2025/01/01.html ']'
++ dirname code/../2025/01/01.html
+ mkdir -p code/../2025/01
+ find ../dandiarchive-logs/2025/01/01.log -iname '[0-9][0-9]*' -type f '!' -path '*/.git/*'
+ goaccess -o code/../2025/01/01.html --log-format AWSS3 --no-parsing-spinner --no-progress
+ xargs grep -v 'S3\.EXPIRE\.OBJECT'

and then if I remove that generated file and rerun -- kaboom

dandi@drogon:/mnt/backup/dandi/dandiarchive-logs-goaccess-logs$ rm 2025/01/01.html
dandi@drogon:/mnt/backup/dandi/dandiarchive-logs-goaccess-logs$ duct bash -x code/process_log ../dandiarchive-logs/2025/01/01.log
2025-03-28T07:41:53-0400 [INFO    ] con-duct: duct is executing 'bash -x code/process_log ../dandiarchive-logs/2025/01/01.log'...
2025-03-28T07:41:53-0400 [INFO    ] con-duct: Log files will be written to .duct/logs/2025.03.28T07.41.53-680321_
+ set -eu
+ logs_topdir=/mnt/backup/dandi/dandiarchive-logs
++ dirname code/process_log
+ topdir=code/..
+ force=
+ for in_log in "$@"
++ sed -E 's#.*/([0-9]{4}/[0-9]{2}(/[0-9]{2})?).*#\1#'
++ echo ../dandiarchive-logs/2025/01/01.log
+ log_date=2025/01/01
+ o_log=code/../2025/01/01.html
+ '[' -e code/../2025/01/01.html ']'
++ dirname code/../2025/01/01.html
+ mkdir -p code/../2025/01
+ goaccess -o code/../2025/01/01.html --log-format AWSS3 --no-parsing-spinner --no-progress

GoAccess - version 1.7 - Jan  4 2023 18:36:47
Config file: /etc/goaccess/goaccess.conf

Fatal error has occurred
Error occurred at: src/goaccess.c - initializer - 1471
No input data was provided nor there's data to restore.

+ xargs grep -v 'S3\.EXPIRE\.OBJECT'
+ find ../dandiarchive-logs/2025/01/01.log -iname '[0-9][0-9]*' -type f '!' -path '*/.git/*'
xargs: grep: terminated by signal 13
2025-03-28T07:41:53-0400 [INFO    ] con-duct: Summary:
Exit Code: 1
Command: bash -x code/process_log ../dandiarchive-logs/2025/01/01.log
Log files location: .duct/logs/2025.03.28T07.41.53-680321_
Wall Clock Time: 0.041 sec
Memory Peak Usage (RSS): 3.3 MB
Memory Average Usage (RSS): 3.3 MB
Virtual Memory Peak Usage (VSZ): 7.1 MB
Virtual Memory Average Usage (VSZ): 7.1 MB
Memory Peak Percentage: 0.0%
Memory Average Percentage: 0.0%
CPU Peak Usage: 0.0%
Average CPU Usage: 0.0%

happened originally with 0.8.0 and this one with bleeding edge 0.12.0.post8+g1650794 .

here is with debug output
dandi@drogon:/mnt/backup/dandi/dandiarchive-logs-goaccess-logs$ duct -l DEBUG bash -x code/process_log ../dandiarchive-logs/2025/01/01.log
2025-03-28T07:45:15-0400 [INFO    ] con-duct: duct is executing 'bash -x code/process_log ../dandiarchive-logs/2025/01/01.log'...
2025-03-28T07:45:15-0400 [INFO    ] con-duct: Log files will be written to .duct/logs/2025.03.28T07.45.15-680848_
2025-03-28T07:45:15-0400 [DEBUG   ] con-duct: Starting monitoring of the process <Popen: returncode: None args: ['bash', '-x', 'code/process_log', '../dandia...> on sample interval 1.000000 for report interval 60.000000
+ set -eu
+ logs_topdir=/mnt/backup/dandi/dandiarchive-logs
++ dirname code/process_log
+ topdir=code/..
+ force=
+ for in_log in "$@"
++ sed -E 's#.*/([0-9]{4}/[0-9]{2}(/[0-9]{2})?).*#\1#'
++ echo ../dandiarchive-logs/2025/01/01.log
+ log_date=2025/01/01
+ o_log=code/../2025/01/01.html
+ '[' -e code/../2025/01/01.html ']'
++ dirname code/../2025/01/01.html
+ mkdir -p code/../2025/01
+ find ../dandiarchive-logs/2025/01/01.log -iname '[0-9][0-9]*' -type f '!' -path '*/.git/*'
+ goaccess -o code/../2025/01/01.html --log-format AWSS3 --no-parsing-spinner --no-progress
+ xargs grep -v 'S3\.EXPIRE\.OBJECT'

GoAccess - version 1.7 - Jan  4 2023 18:36:47
Config file: /etc/goaccess/goaccess.conf

Fatal error has occurred
Error occurred at: src/goaccess.c - initializer - 1471
No input data was provided nor there's data to restore.

2025-03-28T07:45:15-0400 [DEBUG   ] con-duct: Process ended, setting stop_event to stop monitoring thread
2025-03-28T07:45:15-0400 [DEBUG   ] con-duct: Waiting for monitoring thread to finish
xargs: grep: terminated by signal 13
2025-03-28T07:45:15-0400 [DEBUG   ] con-duct: Breaking out because stop event was set
2025-03-28T07:45:15-0400 [DEBUG   ] con-duct: Monitoring thread finished
2025-03-28T07:45:15-0400 [DEBUG   ] con-duct: Waiting for environment collection thread to finish
2025-03-28T07:45:15-0400 [DEBUG   ] con-duct: Environment collection finished
2025-03-28T07:45:15-0400 [DEBUG   ] con-duct: Waiting for system information collection thread to finish
2025-03-28T07:45:15-0400 [DEBUG   ] con-duct: System information collection finished
2025-03-28T07:45:15-0400 [INFO    ] con-duct: Removing log files since command failed in less than 3.0 seconds.
seems to be specifically about `| xargs grep -v` component since if removed -- works fine
dandi@drogon:/mnt/backup/dandi/dandiarchive-logs-goaccess-logs$ bash -c "find ../dandiarchive-logs/2025/01/01.log -iname '[0-9][0-9]*' -type f -not -path '*/.git/*' | xargs grep -v 'S3\.EXPIRE\.OBJECT' | goaccess -o code/../2025/01/01.html --log-format AWSS3 --no-parsing-spinner --no-progress"
dandi@drogon:/mnt/backup/dandi/dandiarchive-logs-goaccess-logs$ ls -l 2025/01/01.html                                                                                                                                             -rw-r--r-- 1 dandi dandi 760070 Mar 28 07:48 2025/01/01.html
dandi@drogon:/mnt/backup/dandi/dandiarchive-logs-goaccess-logs$ duct bash -c "find ../dandiarchive-logs/2025/01/01.log -iname '[0-9][0-9]*' -type f -not -path '*/.git/*' | xargs grep -v 'S3\.EXPIRE\.OBJECT' | goaccess -o code/../2025/01/01.html --log-format AWSS3 --no-parsing-spinner --no-progress"
2025-03-28T07:48:21-0400 [INFO    ] con-duct: duct is executing "bash -c find ../dandiarchive-logs/2025/01/01.log -iname '[0-9][0-9]*' -type f -not -path '*/.git/*' | xargs grep -v 'S3\\.EXPIRE\\.OBJECT' | goaccess -o code/../2025/01/01.html --log-format AWSS3 --no-parsing-spinner --no-progress"...
2025-03-28T07:48:21-0400 [INFO    ] con-duct: Log files will be written to .duct/logs/2025.03.28T07.48.21-685844_

GoAccess - version 1.7 - Jan  4 2023 18:36:47
Config file: /etc/goaccess/goaccess.conf

Fatal error has occurred
Error occurred at: src/goaccess.c - initializer - 1471
No input data was provided nor there's data to restore.

xargs: grep: terminated by signal 13
2025-03-28T07:48:21-0400 [INFO    ] con-duct: Removing log files since command failed in less than 3.0 seconds.
dandi@drogon:/mnt/backup/dandi/dandiarchive-logs-goaccess-logs$ ls -l 2025/01/01.html                                                                                                                                             -rw-r--r-- 1 dandi dandi 760070 Mar 28 07:48 2025/01/01.html
dandi@drogon:/mnt/backup/dandi/dandiarchive-logs-goaccess-logs$ duct bash -c "find ../dandiarchive-logs/2025/01/01.log -iname '[0-9][0-9]*' -type f -not -path '*/.git/*' | xargs goaccess -o code/../2025/01/01.html --log-format AWSS3 --no-parsing-spinner --no-progress"
2025-03-28T07:48:45-0400 [INFO    ] con-duct: duct is executing "bash -c find ../dandiarchive-logs/2025/01/01.log -iname '[0-9][0-9]*' -type f -not -path '*/.git/*' | xargs goaccess -o code/../2025/01/01.html --log-format AWSS3 --no-parsing-spinner --no-progress"...
2025-03-28T07:48:45-0400 [INFO    ] con-duct: Log files will be written to .duct/logs/2025.03.28T07.48.45-685857_
2025-03-28T07:48:52-0400 [INFO    ] con-duct: Summary:
Exit Code: 0
Command: bash -c find ../dandiarchive-logs/2025/01/01.log -iname '[0-9][0-9]*' -type f -not -path '*/.git/*' | xargs goaccess -o code/../2025/01/01.html --log-format AWSS3 --no-parsing-spinner --no-progress
Log files location: .duct/logs/2025.03.28T07.48.45-685857_
Wall Clock Time: 6.820 sec
Memory Peak Usage (RSS): 27.2 MB
Memory Average Usage (RSS): 21.3 MB
Virtual Memory Peak Usage (VSZ): 46.3 MB
Virtual Memory Average Usage (VSZ): 39.6 MB
Memory Peak Percentage: 0.00%
Memory Average Percentage: 0.00%
CPU Peak Usage: 40.90%
Average CPU Usage: 29.51%

dandi@drogon:/mnt/backup/dandi/dandiarchive-logs-goaccess-logs$ ls -l 2025/01/01.html                                                                                                                                             -rw-r--r-- 1 dandi dandi 760111 Mar 28 07:48 2025/01/01.html
dandi@drogon:/mnt/backup/dandi/dandiarchive-logs-goaccess-logs$ rm 2025/01/01.html
dandi@drogon:/mnt/backup/dandi/dandiarchive-logs-goaccess-logs$ ls -l 2025/01/01.html
ls: cannot access '2025/01/01.html': No such file or directory
dandi@drogon:/mnt/backup/dandi/dandiarchive-logs-goaccess-logs$ duct bash -c "find ../dandiarchive-logs/2025/01/01.log -iname '[0-9][0-9]*' -type f -not -path '*/.git/*' | xargs goaccess -o code/../2025/01/01.html --log-format AWSS3 --no-parsing-spinner --no-progress"
2025-03-28T07:49:14-0400 [INFO    ] con-duct: duct is executing "bash -c find ../dandiarchive-logs/2025/01/01.log -iname '[0-9][0-9]*' -type f -not -path '*/.git/*' | xargs goaccess -o code/../2025/01/01.html --log-format AWSS3 --no-parsing-spinner --no-progress"...
2025-03-28T07:49:14-0400 [INFO    ] con-duct: Log files will be written to .duct/logs/2025.03.28T07.49.14-685878_
2025-03-28T07:49:18-0400 [INFO    ] con-duct: Summary:
Exit Code: 0
Command: bash -c find ../dandiarchive-logs/2025/01/01.log -iname '[0-9][0-9]*' -type f -not -path '*/.git/*' | xargs goaccess -o code/../2025/01/01.html --log-format AWSS3 --no-parsing-spinner --no-progress
Log files location: .duct/logs/2025.03.28T07.49.14-685878_
Wall Clock Time: 3.263 sec
Memory Peak Usage (RSS): 26.4 MB
Memory Average Usage (RSS): 19.0 MB
Virtual Memory Peak Usage (VSZ): 45.5 MB
Virtual Memory Average Usage (VSZ): 37.5 MB
Memory Peak Percentage: 0.00%
Memory Average Percentage: 0.00%
CPU Peak Usage: 51.80%
Average CPU Usage: 37.38%

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions