Aws-cli: download-db-log-file-portion with starting token of 0 not working as documented

[sstarcher]

From the documentation for aws rds download-db-log-file-portion

In  order  to  download  the  entire  file, you need --starting-token 0
       parameter:

          aws rds download-db-log-file-portion --db-instance-identifier myinstance \
          --log-file-name log.txt --starting-token 0 --output text > full.txt```

command: `aws rds download-db-log-file-portion --db-instance-identifier instance --log-file-name error/log_file --starting-token 0`  This file is over 700mb in size.  According to the documentation I should get the entire file, but instead the file is truncated.

Actual results show the data is being truncated.

{
    "LogFileData": "2018-01-09 15:00:00...
...\n [Your log message was truncated]\n"
}

CLI Version

aws --version                                                                                                      
aws-cli/1.14.20 Python/3.6.4 Darwin/17.3.0 botocore/1.8.24

Related issues:
https://github.com/aws/aws-cli/issues/2745
https://github.com/aws/aws-cli/issues/2268

Debug output with log information stripped

aws rds download-db-log-file-portion --db-instance-identifier xxxx --log-file-name error/xxxx --starting-token 0 --debug 2> out

2018-01-10 09:34:10,630 - MainThread - awscli.clidriver - DEBUG - CLI version: aws-cli/1.14.20 Python/3.6.4 Darwin/17.3.0 botocore/1.8.24
2018-01-10 09:34:10,630 - MainThread - awscli.clidriver - DEBUG - Arguments entered to CLI: ['rds', 'download-db-log-file-portion', '--db-instance-identifier', 'db-instance', '--log-file-name', 'error/logfile', '--starting-token', '0', '--debug']
2018-01-10 09:34:10,631 - MainThread - botocore.hooks - DEBUG - Event session-initialized: calling handler <function add_scalar_parsers at 0x109c11840>
2018-01-10 09:34:10,631 - MainThread - botocore.session - DEBUG - Loading variable profile from defaults.
2018-01-10 09:34:10,631 - MainThread - botocore.hooks - DEBUG - Event session-initialized: calling handler <function inject_assume_role_provider_cache at 0x10970ba60>
2018-01-10 09:34:10,631 - MainThread - botocore.session - DEBUG - Loading variable profile from defaults.
2018-01-10 09:34:10,631 - MainThread - botocore.session - DEBUG - Loading variable credentials_file from defaults.
2018-01-10 09:34:10,631 - MainThread - botocore.session - DEBUG - Loading variable config_file from defaults.
2018-01-10 09:34:10,631 - MainThread - botocore.session - DEBUG - Loading variable profile from defaults.
2018-01-10 09:34:10,631 - MainThread - botocore.session - DEBUG - Loading variable metadata_service_timeout from defaults.
2018-01-10 09:34:10,631 - MainThread - botocore.session - DEBUG - Loading variable profile from defaults.
2018-01-10 09:34:10,631 - MainThread - botocore.session - DEBUG - Loading variable metadata_service_num_attempts from defaults.
2018-01-10 09:34:10,632 - MainThread - botocore.session - DEBUG - Loading variable profile from defaults.
2018-01-10 09:34:10,632 - MainThread - botocore.hooks - DEBUG - Event session-initialized: calling handler <function attach_history_handler at 0x1099bae18>
2018-01-10 09:34:10,632 - MainThread - botocore.session - DEBUG - Loading variable profile from defaults.
2018-01-10 09:34:10,632 - MainThread - botocore.session - DEBUG - Loading variable profile from defaults.
2018-01-10 09:34:10,632 - MainThread - botocore.session - DEBUG - Loading variable api_versions from defaults.
2018-01-10 09:34:10,633 - MainThread - botocore.loaders - DEBUG - Loading JSON file: /usr/local/Cellar/awscli/1.14.20/libexec/lib/python3.6/site-packages/botocore/data/rds/2014-10-31/service-2.json
2018-01-10 09:34:10,641 - MainThread - botocore.loaders - DEBUG - Loading JSON file: /usr/local/Cellar/awscli/1.14.20/libexec/lib/python3.6/site-packages/botocore/data/rds/2014-10-31/service-2.sdk-extras.json
2018-01-10 09:34:10,641 - MainThread - botocore.hooks - DEBUG - Event service-data-loaded.rds: calling handler <function register_retries_for_service at 0x1092ae268>
2018-01-10 09:34:10,642 - MainThread - botocore.handlers - DEBUG - Registering retry handlers for service: rds
2018-01-10 09:34:10,644 - MainThread - botocore.hooks - DEBUG - Event building-command-table.rds: calling handler <function _building_command_table at 0x109b98f28>
2018-01-10 09:34:10,644 - MainThread - botocore.hooks - DEBUG - Event service-data-loaded.rds: calling handler <function register_retries_for_service at 0x1092ae268>
2018-01-10 09:34:10,644 - MainThread - botocore.handlers - DEBUG - Registering retry handlers for service: rds
2018-01-10 09:34:10,644 - MainThread - botocore.hooks - DEBUG - Event building-command-table.rds: calling handler <function _add_generate_db_auth_token at 0x109b98d90>
2018-01-10 09:34:10,645 - MainThread - botocore.hooks - DEBUG - Event building-command-table.rds: calling handler <function add_waiters at 0x109c16a60>
2018-01-10 09:34:10,650 - MainThread - botocore.loaders - DEBUG - Loading JSON file: /usr/local/Cellar/awscli/1.14.20/libexec/lib/python3.6/site-packages/botocore/data/rds/2014-10-31/waiters-2.json
2018-01-10 09:34:10,651 - MainThread - awscli.clidriver - DEBUG - OrderedDict([('db-instance-identifier', <awscli.arguments.CLIArgument object at 0x109f1dd30>), ('log-file-name', <awscli.arguments.CLIArgument object at 0x109f1dd68>), ('marker', <awscli.arguments.CLIArgument object at 0x109f1ddd8>), ('number-of-lines', <awscli.arguments.CLIArgument object at 0x109f1de10>)])
2018-01-10 09:34:10,651 - MainThread - botocore.hooks - DEBUG - Event building-argument-table.rds.download-db-log-file-portion: calling handler <function add_streaming_output_arg at 0x109c11ae8>
2018-01-10 09:34:10,651 - MainThread - botocore.hooks - DEBUG - Event building-argument-table.rds.download-db-log-file-portion: calling handler <function add_cli_input_json at 0x10970bea0>
2018-01-10 09:34:10,652 - MainThread - botocore.hooks - DEBUG - Event building-argument-table.rds.download-db-log-file-portion: calling handler <function unify_paging_params at 0x109b8f510>
2018-01-10 09:34:10,658 - MainThread - botocore.loaders - DEBUG - Loading JSON file: /usr/local/Cellar/awscli/1.14.20/libexec/lib/python3.6/site-packages/botocore/data/rds/2014-10-31/paginators-1.json
2018-01-10 09:34:10,658 - MainThread - awscli.customizations.paginate - DEBUG - Modifying paging parameters for operation: DownloadDBLogFilePortion
2018-01-10 09:34:10,658 - MainThread - botocore.hooks - DEBUG - Event building-argument-table.rds.download-db-log-file-portion: calling handler <function add_generate_skeleton at 0x109b73d90>
2018-01-10 09:34:10,658 - MainThread - botocore.hooks - DEBUG - Event before-building-argument-table-parser.rds.download-db-log-file-portion: calling handler <bound method OverrideRequiredArgsArgument.override_required_args of <awscli.customizations.cliinputjson.CliInputJSONArgument object at 0x109f1de80>>
2018-01-10 09:34:10,658 - MainThread - botocore.hooks - DEBUG - Event before-building-argument-table-parser.rds.download-db-log-file-portion: calling handler <bound method GenerateCliSkeletonArgument.override_required_args of <awscli.customizations.generatecliskeleton.GenerateCliSkeletonArgument object at 0x109f2e4e0>>
2018-01-10 09:34:10,659 - MainThread - botocore.hooks - DEBUG - Event operation-args-parsed.rds.download-db-log-file-portion: calling handler functools.partial(<function check_should_enable_pagination at 0x109b8f620>, ['marker', 'number-of-lines'], {}, OrderedDict([('db-instance-identifier', <awscli.arguments.CLIArgument object at 0x109f1dd30>), ('log-file-name', <awscli.arguments.CLIArgument object at 0x109f1dd68>), ('marker', <awscli.arguments.CLIArgument object at 0x109f1ddd8>), ('number-of-lines', <awscli.arguments.CLIArgument object at 0x109f1de10>), ('cli-input-json', <awscli.customizations.cliinputjson.CliInputJSONArgument object at 0x109f1de80>), ('starting-token', <awscli.customizations.paginate.PageArgument object at 0x109f1deb8>), ('page-size', <awscli.customizations.paginate.PageArgument object at 0x109f2e390>), ('max-items', <awscli.customizations.paginate.PageArgument object at 0x109f2e438>), ('generate-cli-skeleton', <awscli.customizations.generatecliskeleton.GenerateCliSkeletonArgument object at 0x109f2e4e0>)]))
2018-01-10 09:34:10,659 - MainThread - botocore.hooks - DEBUG - Event load-cli-arg.rds.download-db-log-file-portion.db-instance-identifier: calling handler <function uri_param at 0x10969b9d8>
2018-01-10 09:34:10,660 - MainThread - botocore.hooks - DEBUG - Event process-cli-arg.rds.download-db-log-file-portion: calling handler <awscli.argprocess.ParamShorthandParser object at 0x1096b3fd0>
2018-01-10 09:34:10,660 - MainThread - awscli.arguments - DEBUG - Unpacked value of 'db-instance' for parameter "db_instance_identifier": 'db-instance'
2018-01-10 09:34:10,660 - MainThread - botocore.hooks - DEBUG - Event load-cli-arg.rds.download-db-log-file-portion.log-file-name: calling handler <function uri_param at 0x10969b9d8>
2018-01-10 09:34:10,660 - MainThread - botocore.hooks - DEBUG - Event process-cli-arg.rds.download-db-log-file-portion: calling handler <awscli.argprocess.ParamShorthandParser object at 0x1096b3fd0>
2018-01-10 09:34:10,660 - MainThread - awscli.arguments - DEBUG - Unpacked value of 'error/logfile' for parameter "log_file_name": 'error/logfile'
2018-01-10 09:34:10,660 - MainThread - botocore.hooks - DEBUG - Event load-cli-arg.rds.download-db-log-file-portion.marker: calling handler <function uri_param at 0x10969b9d8>
2018-01-10 09:34:10,660 - MainThread - botocore.hooks - DEBUG - Event load-cli-arg.rds.download-db-log-file-portion.number-of-lines: calling handler <function uri_param at 0x10969b9d8>
2018-01-10 09:34:10,660 - MainThread - botocore.hooks - DEBUG - Event load-cli-arg.rds.download-db-log-file-portion.cli-input-json: calling handler <function uri_param at 0x10969b9d8>
2018-01-10 09:34:10,660 - MainThread - botocore.hooks - DEBUG - Event load-cli-arg.rds.download-db-log-file-portion.starting-token: calling handler <function uri_param at 0x10969b9d8>
2018-01-10 09:34:10,660 - MainThread - botocore.hooks - DEBUG - Event load-cli-arg.rds.download-db-log-file-portion.page-size: calling handler <function uri_param at 0x10969b9d8>
2018-01-10 09:34:10,660 - MainThread - botocore.hooks - DEBUG - Event load-cli-arg.rds.download-db-log-file-portion.max-items: calling handler <function uri_param at 0x10969b9d8>
2018-01-10 09:34:10,660 - MainThread - botocore.hooks - DEBUG - Event load-cli-arg.rds.download-db-log-file-portion.generate-cli-skeleton: calling handler <function uri_param at 0x10969b9d8>
2018-01-10 09:34:10,660 - MainThread - botocore.hooks - DEBUG - Event calling-command.rds.download-db-log-file-portion: calling handler <bound method CliInputJSONArgument.add_to_call_parameters of <awscli.customizations.cliinputjson.CliInputJSONArgument object at 0x109f1de80>>
2018-01-10 09:34:10,660 - MainThread - botocore.hooks - DEBUG - Event calling-command.rds.download-db-log-file-portion: calling handler <bound method GenerateCliSkeletonArgument.generate_json_skeleton of <awscli.customizations.generatecliskeleton.GenerateCliSkeletonArgument object at 0x109f2e4e0>>
2018-01-10 09:34:10,660 - MainThread - botocore.session - DEBUG - Loading variable profile from defaults.
2018-01-10 09:34:10,661 - MainThread - botocore.session - DEBUG - Loading variable profile from defaults.
2018-01-10 09:34:10,661 - MainThread - botocore.session - DEBUG - Loading variable region from config file with value 'aws-region'.
2018-01-10 09:34:10,661 - MainThread - botocore.session - DEBUG - Loading variable profile from defaults.
2018-01-10 09:34:10,661 - MainThread - botocore.session - DEBUG - Loading variable ca_bundle from defaults.
2018-01-10 09:34:10,661 - MainThread - botocore.session - DEBUG - Loading variable profile from defaults.
2018-01-10 09:34:10,661 - MainThread - botocore.session - DEBUG - Loading variable api_versions from defaults.
2018-01-10 09:34:10,661 - MainThread - botocore.credentials - DEBUG - Looking for credentials via: env
2018-01-10 09:34:10,661 - MainThread - botocore.credentials - DEBUG - Looking for credentials via: assume-role
2018-01-10 09:34:10,661 - MainThread - botocore.credentials - DEBUG - Looking for credentials via: shared-credentials-file
2018-01-10 09:34:10,662 - MainThread - botocore.credentials - INFO - Found credentials in shared credentials file: ~/.aws/credentials
2018-01-10 09:34:10,663 - MainThread - botocore.loaders - DEBUG - Loading JSON file: /usr/local/Cellar/awscli/1.14.20/libexec/lib/python3.6/site-packages/botocore/data/endpoints.json
2018-01-10 09:34:10,665 - MainThread - botocore.session - DEBUG - Loading variable profile from defaults.
2018-01-10 09:34:10,665 - MainThread - botocore.hooks - DEBUG - Event choose-service-name: calling handler <function handle_service_name_alias at 0x109298840>
2018-01-10 09:34:10,668 - MainThread - botocore.hooks - DEBUG - Event creating-client-class.rds: calling handler <function add_generate_db_auth_token at 0x109232bf8>
2018-01-10 09:34:10,668 - MainThread - botocore.hooks - DEBUG - Event creating-client-class.rds: calling handler <function add_generate_presigned_url at 0x109239510>
2018-01-10 09:34:10,668 - MainThread - botocore.args - DEBUG - The s3 config key is not a dictionary type, ignoring its value of: None
2018-01-10 09:34:10,677 - MainThread - botocore.endpoint - DEBUG - Setting rds timeout as (60, 60)
2018-01-10 09:34:10,678 - MainThread - botocore.client - DEBUG - Registering retry handlers for service: rds
2018-01-10 09:34:10,678 - MainThread - botocore.session - DEBUG - Loading variable profile from defaults.
2018-01-10 09:34:10,678 - MainThread - botocore.session - DEBUG - Loading variable profile from defaults.
2018-01-10 09:34:10,678 - MainThread - botocore.session - DEBUG - Loading variable output from config file with value 'json'.
2018-01-10 09:34:10,678 - MainThread - botocore.paginate - DEBUG - Attempting to fall back to old starting token parser. For token: 0
2018-01-10 09:34:10,678 - MainThread - botocore.paginate - DEBUG - Attempting to fall back to old starting token parser. For token: 0
2018-01-10 09:34:10,679 - MainThread - botocore.hooks - DEBUG - Event before-parameter-build.rds.DownloadDBLogFilePortion: calling handler <function generate_idempotent_uuid at 0x1092acb70>
2018-01-10 09:34:10,679 - MainThread - botocore.endpoint - DEBUG - Making request for OperationModel(name=DownloadDBLogFilePortion) (verify_ssl=True) with params: {'url_path': '/', 'query_string': '', 'method': 'POST', 'headers': {'Content-Type': 'application/x-www-form-urlencoded; charset=utf-8', 'User-Agent': 'aws-cli/1.14.20 Python/3.6.4 Darwin/17.3.0 botocore/1.8.24'}, 'body': {'Action': 'DownloadDBLogFilePortion', 'Version': '2014-10-31', 'DBInstanceIdentifier': 'db-instance', 'LogFileName': 'error/logfile', 'Marker': '0'}, 'url': 'https://rds.aws-region.amazonaws.com/', 'context': {'client_region': 'aws-region', 'client_config': <botocore.config.Config object at 0x10a000668>, 'has_streaming_input': False, 'auth_type': None}}
2018-01-10 09:34:10,679 - MainThread - botocore.hooks - DEBUG - Event request-created.rds.DownloadDBLogFilePortion: calling handler <bound method RequestSigner.handler of <botocore.signers.RequestSigner object at 0x10a000588>>
2018-01-10 09:34:10,679 - MainThread - botocore.hooks - DEBUG - Event choose-signer.rds.DownloadDBLogFilePortion: calling handler <function set_operation_specific_signer at 0x1092aca60>
2018-01-10 09:34:10,680 - MainThread - botocore.auth - DEBUG - Calculating signature using v4 auth.
2018-01-10 09:34:10,680 - MainThread - botocore.auth - DEBUG - CanonicalRequest:
POST
/

content-type:application/x-www-form-urlencoded; charset=utf-8
host:rds.aws-region.amazonaws.com
x-amz-date:20180110T143410Z

content-type;host;x-amz-date
24e7f0dc1243da7337fe4b71cd1b33ba341789e2e37bd44654fd29269d4ef8ce
2018-01-10 09:34:10,680 - MainThread - botocore.auth - DEBUG - StringToSign:
AWS4-HMAC-SHA256
20180110T143410Z
20180110/aws-region/rds/aws4_request
c778a189e211e2e7d0f114ca6ff5bfc0470fe944d0c3bdfc916bc2e840da4bbc
2018-01-10 09:34:10,680 - MainThread - botocore.auth - DEBUG - Signature:
13ab07cfdb95d82d66c3aa650e44840be243229b692ba3c52bce4a748bd62d1b
2018-01-10 09:34:10,682 - MainThread - botocore.endpoint - DEBUG - Sending http request: <PreparedRequest [POST]>
2018-01-10 09:34:10,683 - MainThread - botocore.vendored.requests.packages.urllib3.connectionpool - INFO - Starting new HTTPS connection (1): rds.aws-region.amazonaws.com
2018-01-10 09:34:11,339 - MainThread - botocore.vendored.requests.packages.urllib3.connectionpool - DEBUG - "POST / HTTP/1.1" 200 1069820
2018-01-10 09:34:13,178 - MainThread - botocore.parsers - DEBUG - Response headers: {'x-amzn-requestid': '968aebba-1ba8-4adf-bb78-c9c7b136cca1', 'content-type': 'text/xml', 'content-length': '1069820', 'vary': 'Accept-Encoding', 'date': 'Wed, 10 Jan 2018 14:34:10 GMT'}
2018-01-10 09:34:13,178 - MainThread - botocore.parsers - DEBUG - Response body:
b'<DownloadDBLogFilePortionResponse xmlns="http://rds.amazonaws.com/doc/2014-10-31/">\n  <DownloadDBLogFilePortionResult>\n    <AdditionalDataPending>false</AdditionalDataPending>\n    <Marker>15:1048577</Marker>\n    <LogFileData>....\n [Your log message was truncated]\n</LogFileData>\n  </DownloadDBLogFilePortionResult>\n  <ResponseMetadata>\n    <RequestId>968aebba-1ba8-4adf-bb78-c9c7b136cca1</RequestId>\n  </ResponseMetadata>\n</DownloadDBLogFilePortionResponse>\n'
2018-01-10 09:34:13,198 - MainThread - botocore.hooks - DEBUG - Event needs-retry.rds.DownloadDBLogFilePortion: calling handler <botocore.retryhandler.RetryHandler object at 0x109cd4f98>
2018-01-10 09:34:13,198 - MainThread - botocore.retryhandler - DEBUG - No retry needed.
2018-01-10 09:34:13,198 - MainThread - botocore.paginate - DEBUG - Attempting to fall back to old starting token parser. For token: 0

[kyleknap]

Interesting. Thanks for the debug logs that is really helpful. So it looks like the value that the service is returning is literally returning [Your log message was truncated] meaning the value in your db logs is also [Your log message was truncated]. I'm not too sure why your logs file itself would be truncating the message as this happening server side as opposed to client side. I would recommend reaching out to AWS Support or the AWS Developer Forums. Someone there should have more knowledge of the server side logic of why that is happening.

[sstarcher]

@kyleknap I wonder if the API has some changes where you can only request a response of a certain size. If that's the case the documentation for the aws cli should change to reflect that. If that's the case the current documentation is wrong.

[kyleknap]

Looking at the API, you may have some luck with the --page-size parameter. This corresponds to NumberOfLines parameter which will control the maximum number of lines per page returned from the CLI. Otherwise looking at the API documentation, I did not see anything related to the value: [Your log message was truncated].

[sstarcher]

Nope, setting the page size to a high value results in the exact same file output. The documentation you linked specifies
Downloads all or a portion of the specified log file, up to 1 MB in size.

It looks like if a user has a 500mb log file are are using the api they must make 500 aws cli calls.
If this is the case the documentation for aws cli's command needs updated to reflect this.

[sstarcher]

I also just assumed I could update the --starting-token and get the next segment. If I change --starting-token to 1 I get no output. Same thing with several larger values no output. I'm not seeing how to use this command and actually get more than the first 1mb of logs in it's current state.

[jonstacks]

I had the same issue with both the CLI and the SDK. I ended up making a CLI program, rds-logs-download-url, to give me the URL for the full log file so I could just download it. I hope someone else find it useful as well until this issue gets revolved.

[justnance]

Following up here, I don't think there's anything actionable on the CLI side. Kyle provided an explanation about what's happening, and also recommended to reach out to the forums.

Closing issue due to inactivity.

[vosmax]

I've faced with the same issue.
aws rds download-db-log-file-portion --db-instance-identifier myinstance \ --log-file-name log.txt --starting-token 0 --output text > doesn't return the whole log file.
It's returned only 99326 log lines from file (2 minutes of hour).
I've tried to use pagination with --max-items as well, but aws cli doesn't generate token for the last part of log file. For example, file can be divided by three part with 1000 items. On the second portion of data I will get NextToken=null, so I wouldn't get the third part.

[jakubkalicki]

The problem still occurs.

[jonstacks]

@jakubkalicki, I posted this up above, but as a workaround I wrote a cli in golang to programmatically get the download url if you are in need of something right away. rds-logs-download-url. You just need the RDS instance identifier and the name of the log to generate the signed URL. (I used the other aws commands to get these in a bash script and programmatically download the files to feed into something for analytics).

I also hope they add this functionality into the CLI.