iOS Development: Create file failed(return domain:NSCocoaErrorDomain,code:512)

I need to save file to library directory to support retry capability, but some users found it not working.

After some research, I got the following information:

  1. It affects about 100+ users per day, about one in ten thousand of DAU.
  2. 96% of them are iOS 13, others are iOS 9, iOS 10, iOS 12(App lowest support version is iOS9).
  3. Once it occurs, later file creations always failed.
  4. App cant save file to sandbox, including library document temp caches directory, using API [NSString writeToFile:atomically:encoding:error:],the error it returns is "{"localizedRecoveryOptions":"","localizedDescription":"The operation couldn’t be completed.","domain":"NSCocoaErrorDomain","code":512,"localizedFailureReason":"","userInfo":{"NSUserStringVariant":"Folder"},"localizedRecoverySuggestion":""}", The localizedDescription is in Chinese(because the phone locale is Chinese), but I cant type Chinese in the post.
  5. Users some have remaining iCloud storage space and some not. They all have remaining disk stroage space.
  6. The sandbox is not empty, it contains some other files that App creates, but the files cretaed date earlier than the user last reinstall date, may synchronized by iCloud, but the user charging via power, not PC.
  7. The files in sandbox that already exist(eg: sqlite datebase file) can be edited.
  8. Scanning sandbox directory attribute using api -[NSFileManager attributesOfItemAtPath:error:], directory write permission returns "NSFilePosixPermissions":493(755 in Octal).
  9. After reinstall the App, It can create files again, some users after some time(may one day or longer) it occurs agains, the old files come back, newly created files disappear. and other users no more problems.



So why this happned and how can I fix this problem?

Replies

Within

NSCocoaErrorDomain
, error 512 is
NSFileWriteUnknownError
, which I’ll admit is not very instructive. In most situations like this the error’s
userInfo
dictionary contains an
NSUnderlyingErrorKey
property with more info about the error. Any sign of that here?

If you can engage with one of the users hitting this problem, you should ask them to trigger a sysdiagnose log immediately after seeing it. This captures a copy of their system log, which may contain clues as to what’s triggering the problem.

You can learn more about sysdiagnose logs from our Bug Reporting > Profiles and Logs page.

Share and Enjoy

Quinn “The Eskimo!”
Apple Developer Relations, Developer Technical Support, Core OS/Hardware

let myEmail = "eskimo" + "1" + "@apple.com"

Thanks for your replay.

For now I didn't see the any NSUnderlyingErrorKey field for the error. I can get NSUserStringVariant field only.

For the sysdiagnose logs, I will try to contact the user can reproduce the problem, and then attach the logs.

HI,

Thanks for your remind, I remove the log。

After search the long log file. I did not see the direct error message in the context of the file creation. So I list the log above my error(The last line of the log is the error log of file creation, It printed by third parrt library CocoaLumberjack ), may it helps.

If you need any other message, remind me.

2020-02-17 16:31:59.297323 +0800 itunesstored tcp_input [C138.1:3] flags=[S.] seq=2710403315, ack=4213688783, win=8190 state=SYN_SENT rcv_nxt=0, snd_una=4213688782
2020-02-17 16:31:59.297395 +0800 itunesstored nw_flow_connected [C138.1 IPv4#7380eaf2:443 in_progress channel-flow (satisfied (Path is satisfied), interface: pdp_ip0, ipv4, ipv6, dns, expensive)] Transport protocol connected
2020-02-17 16:31:59.297437 +0800 itunesstored boringssl_context_set_handshake_config(1470) [0x10518bec0] set tls_handshake_config_standard
2020-02-17 16:31:59.297439 +0800 itunesstored boringssl_context_set_min_version(324) [0x10518bec0] set 0x0301
2020-02-17 16:31:59.297440 +0800 itunesstored boringssl_context_set_max_version(308) [0x10518bec0] set 0x0304
2020-02-17 16:31:59.297456 +0800 itunesstored boringssl_context_set_cipher_suites(842) [0x10518bec0] Ciphersuite string: TLS_AES_128_GCM_SHA256:TLS_AES_256_GCM_SHA384:TLS_CHACHA20_POLY1305_SHA256:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-SHA384:ECDHE-ECDSA-AES128-SHA256:ECDHE-ECDSA-AES256-SHA:ECDHE-ECDSA-AES128-SHA:ECDHE-ECDSA-CHACHA20-POLY1305:ECDHE-RSA-AES256-GCM-SHA384:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-RSA-AES256-SHA384:ECDHE-RSA-AES128-SHA256:ECDHE-RSA-AES256-SHA:ECDHE-RSA-AES128-SHA:ECDHE-RSA-CHACHA20-POLY1305:AES256-GCM-SHA384:AES128-GCM-SHA256:AES256-SHA256:AES128-SHA256:AES256-SHA:AES128-SHA:ECDHE-ECDSA-AES128-SHA:ECDHE-ECDSA-AES256-SHA:ECDHE-RSA-AES128-SHA:ECDHE-RSA-AES256-SHA:AES256-SHA:AES128-SHA:ECDHE-ECDSA-DES-CBC3-SHA:ECDHE-RSA-DES-CBC3-SHA:DES-CBC3-SHA
2020-02-17 16:31:59.297502 +0800 itunesstored boringssl_context_set_remote_address(2554) [0x10518bec0] Saving remote IPv4 address
2020-02-17 16:31:59.297519 +0800 itunesstored boringssl_session_install_association_state(1297) [0x10518bec0] Client session cache miss
2020-02-17 16:31:59.297523 +0800 itunesstored boringssl_session_set_peer_hostname(1189) [0x10518bec0] SNI <private>
2020-02-17 16:31:59.297538 +0800 itunesstored boringssl_context_set_min_version(324) [C138.1:2][0x10518bec0] set 0x0301
2020-02-17 16:31:59.297544 +0800 itunesstored boringssl_context_set_session_ticket_enabled(439) [C138.1:2][0x10518bec0] set false
2020-02-17 16:31:59.297545 +0800 itunesstored boringssl_context_set_false_start(409) [C138.1:2][0x10518bec0] set false
2020-02-17 16:31:59.297548 +0800 itunesstored boringssl_context_set_enforce_ev(399) [C138.1:2][0x10518bec0] set false
2020-02-17 16:31:59.297549 +0800 itunesstored boringssl_context_set_ats_enforced(1320) [C138.1:2][0x10518bec0] set false
2020-02-17 16:31:59.297549 +0800 itunesstored boringssl_context_set_ats_minimum_rsa_key_size(1329) [C138.1:2][0x10518bec0] set 0
2020-02-17 16:31:59.297550 +0800 itunesstored boringssl_context_set_ats_minimum_ecdsa_key_size(1338) [C138.1:2][0x10518bec0] set 0
2020-02-17 16:31:59.297552 +0800 itunesstored boringssl_context_set_ats_minimum_signature_algorithm(1348) [C138.1:2][0x10518bec0] set 0
2020-02-17 16:31:59.297561 +0800 itunesstored boringssl_session_set_peer_hostname(1189) [C138.1:2][0x10518bec0] SNI <private>
2020-02-17 16:31:59.297601 +0800 itunesstored boringssl_context_set_cipher_suites(842) [C138.1:2][0x10518bec0] Ciphersuite string: TLS_AES_128_GCM_SHA256:TLS_AES_256_GCM_SHA384:TLS_CHACHA20_POLY1305_SHA256:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-SHA384:ECDHE-ECDSA-AES128-SHA256:ECDHE-ECDSA-AES256-SHA:ECDHE-ECDSA-AES128-SHA:ECDHE-ECDSA-CHACHA20-POLY1305:ECDHE-RSA-AES256-GCM-SHA384:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-RSA-AES256-SHA384:ECDHE-RSA-AES128-SHA256:ECDHE-RSA-AES256-SHA:ECDHE-RSA-AES128-SHA:ECDHE-RSA-CHACHA20-POLY1305:AES256-GCM-SHA384:AES128-GCM-SHA256:AES256-SHA256:AES128-SHA256:AES256-SHA:AES128-SHA:ECDHE-ECDSA-AES128-SHA:ECDHE-ECDSA-AES256-SHA:ECDHE-RSA-AES128-SHA:ECDHE-RSA-AES256-SHA:AES256-SHA:AES128-SHA:ECDHE-ECDSA-DES-CBC3-SHA:ECDHE-RSA-DES-CBC3-SHA:DES-CBC3-SHA
2020-02-17 16:31:59.297647 +0800 itunesstored nw_protocol_boringssl_begin_connection(497) [C138.1:2][0x10518bec0] early data disabled
2020-02-17 16:31:59.297652 +0800 itunesstored boringssl_context_info_handler(1969) [C138.1:2][0x10518bec0] Client handshake started
2020-02-17 16:31:59.297791 +0800 itunesstored boringssl_context_message_handler(2257) [C138.1:2][0x10518bec0] Writing SSL3_RT_HANDSHAKE 512 bytes
2020-02-17 16:31:59.297795 +0800 itunesstored boringssl_context_info_handler(1982) [C138.1:2][0x10518bec0] Client handshake state: TLS client enter_early_data
2020-02-17 16:31:59.297796 +0800 itunesstored boringssl_context_add_handshake_message_pending(577) [C138.1:2][0x10518bec0] Adding message(1)
2020-02-17 16:31:59.297841 +0800 itunesstored boringssl_context_info_handler(1982) [C138.1:2][0x10518bec0] Client handshake state: TLS client read_server_hello
2020-02-17 16:31:59.297842 +0800 itunesstored boringssl_context_add_handshake_message_pending(577) [C138.1:2][0x10518bec0] Adding message(2)
2020-02-17 16:31:59.297862 +0800 itunesstored boringssl_session_handshake_incomplete(191) [C138.1:2][0x10518bec0] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.297864 +0800 itunesstored boringssl_session_handshake_incomplete(191) [C138.1:2][0x10518bec0] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.297971 +0800 itunesstored boringssl_session_handshake_incomplete(191) [C138.1:2][0x10518bec0] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.297975 +0800 itunesstored boringssl_session_handshake_incomplete(191) [C138.1:2][0x10518bec0] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.307384 +0800 putong Task <4ADB652E-F146-4AEB-BACD-0CE24C0D166A>.<0> received response, status 200 content K
2020-02-17 16:31:59.307545 +0800 putong Task <4ADB652E-F146-4AEB-BACD-0CE24C0D166A>.<0> response ended
2020-02-17 16:31:59.307559 +0800 putong Task <4ADB652E-F146-4AEB-BACD-0CE24C0D166A>.<0> done using Connection 2
2020-02-17 16:31:59.307765 +0800 putong Task <4ADB652E-F146-4AEB-BACD-0CE24C0D166A>.<0> summary for task success {transaction_duration_ms=224, response_status=200, connection=2, protocol="http/1.1", domain_lookup_duration_ms=1, connect_duration_ms=111, secure_connection_duration_ms=0, request_start_ms=113, request_duration_ms=0, response_start_ms=224, response_duration_ms=0, request_bytes=420, response_bytes=256, cache_hit=0}
2020-02-17 16:31:59.332356 +0800 putong tcp_input [C6.1:3] flags=[S.] seq=1269118196, ack=2721853098, win=28960 state=SYN_SENT rcv_nxt=0, snd_una=2721853097
2020-02-17 16:31:59.332397 +0800 putong nw_flow_connected [C6.1 IPv4#aea2b038:443 in_progress channel-flow (satisfied (Path is satisfied), interface: pdp_ip0, ipv4, ipv6, dns, expensive)] Transport protocol connected
2020-02-17 16:31:59.332447 +0800 putong boringssl_context_set_min_version(324) [0x10b9786e0] set 0x0301
2020-02-17 16:31:59.332447 +0800 putong boringssl_context_set_handshake_config(1470) [0x10b9786e0] set tls_handshake_config_standard
2020-02-17 16:31:59.332448 +0800 putong boringssl_context_set_max_version(308) [0x10b9786e0] set 0x0304
2020-02-17 16:31:59.332457 +0800 putong boringssl_context_set_cipher_suites(842) [0x10b9786e0] Ciphersuite string: TLS_AES_128_GCM_SHA256:TLS_AES_256_GCM_SHA384:TLS_CHACHA20_POLY1305_SHA256:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-SHA384:ECDHE-ECDSA-AES128-SHA256:ECDHE-ECDSA-AES256-SHA:ECDHE-ECDSA-AES128-SHA:ECDHE-ECDSA-CHACHA20-POLY1305:ECDHE-RSA-AES256-GCM-SHA384:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-RSA-AES256-SHA384:ECDHE-RSA-AES128-SHA256:ECDHE-RSA-AES256-SHA:ECDHE-RSA-AES128-SHA:ECDHE-RSA-CHACHA20-POLY1305:AES256-GCM-SHA384:AES128-GCM-SHA256:AES256-SHA256:AES128-SHA256:AES256-SHA:AES128-SHA:ECDHE-ECDSA-AES128-SHA:ECDHE-ECDSA-AES256-SHA:ECDHE-RSA-AES128-SHA:ECDHE-RSA-AES256-SHA:AES256-SHA:AES128-SHA:ECDHE-ECDSA-DES-CBC3-SHA:ECDHE-RSA-DES-CBC3-SHA:DES-CBC3-SHA
2020-02-17 16:31:59.332482 +0800 putong boringssl_context_set_remote_address(2554) [0x10b9786e0] Saving remote IPv4 address
2020-02-17 16:31:59.332489 +0800 putong boringssl_session_install_association_state(1297) [0x10b9786e0] Client session cache miss
2020-02-17 16:31:59.332489 +0800 putong boringssl_session_set_peer_hostname(1189) [0x10b9786e0] SNI <private>
2020-02-17 16:31:59.332503 +0800 putong boringssl_context_set_min_version(324) [C6.1:2][0x10b9786e0] set 0x0301
2020-02-17 16:31:59.332504 +0800 putong boringssl_context_set_false_start(409) [C6.1:2][0x10b9786e0] set false
2020-02-17 16:31:59.332504 +0800 putong boringssl_context_set_session_ticket_enabled(439) [C6.1:2][0x10b9786e0] set false
2020-02-17 16:31:59.332504 +0800 putong boringssl_context_set_ats_enforced(1320) [C6.1:2][0x10b9786e0] set false
2020-02-17 16:31:59.332504 +0800 putong boringssl_context_set_enforce_ev(399) [C6.1:2][0x10b9786e0] set false
2020-02-17 16:31:59.332505 +0800 putong boringssl_context_set_ats_minimum_signature_algorithm(1348) [C6.1:2][0x10b9786e0] set 0
2020-02-17 16:31:59.332505 +0800 putong boringssl_context_set_ats_minimum_ecdsa_key_size(1338) [C6.1:2][0x10b9786e0] set 0
2020-02-17 16:31:59.332505 +0800 putong boringssl_context_set_ats_minimum_rsa_key_size(1329) [C6.1:2][0x10b9786e0] set 0
2020-02-17 16:31:59.332509 +0800 putong boringssl_session_set_peer_hostname(1189) [C6.1:2][0x10b9786e0] SNI <private>
2020-02-17 16:31:59.332515 +0800 putong boringssl_context_set_cipher_suites(842) [C6.1:2][0x10b9786e0] Ciphersuite string: TLS_AES_128_GCM_SHA256:TLS_AES_256_GCM_SHA384:TLS_CHACHA20_POLY1305_SHA256:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-SHA384:ECDHE-ECDSA-AES128-SHA256:ECDHE-ECDSA-AES256-SHA:ECDHE-ECDSA-AES128-SHA:ECDHE-ECDSA-CHACHA20-POLY1305:ECDHE-RSA-AES256-GCM-SHA384:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-RSA-AES256-SHA384:ECDHE-RSA-AES128-SHA256:ECDHE-RSA-AES256-SHA:ECDHE-RSA-AES128-SHA:ECDHE-RSA-CHACHA20-POLY1305:AES256-GCM-SHA384:AES128-GCM-SHA256:AES256-SHA256:AES128-SHA256:AES256-SHA:AES128-SHA:ECDHE-ECDSA-AES128-SHA:ECDHE-ECDSA-AES256-SHA:ECDHE-RSA-AES128-SHA:ECDHE-RSA-AES256-SHA:AES256-SHA:AES128-SHA:ECDHE-ECDSA-DES-CBC3-SHA:ECDHE-RSA-DES-CBC3-SHA:DES-CBC3-SHA
2020-02-17 16:31:59.332542 +0800 putong nw_protocol_boringssl_begin_connection(497) [C6.1:2][0x10b9786e0] early data disabled
2020-02-17 16:31:59.332545 +0800 putong boringssl_context_info_handler(1969) [C6.1:2][0x10b9786e0] Client handshake started
2020-02-17 16:31:59.332581 +0800 putong boringssl_context_message_handler(2257) [C6.1:2][0x10b9786e0] Writing SSL3_RT_HANDSHAKE 512 bytes
2020-02-17 16:31:59.332582 +0800 putong boringssl_context_info_handler(1982) [C6.1:2][0x10b9786e0] Client handshake state: TLS client enter_early_data
2020-02-17 16:31:59.332583 +0800 putong boringssl_context_add_handshake_message_pending(577) [C6.1:2][0x10b9786e0] Adding message(1)
2020-02-17 16:31:59.332595 +0800 putong boringssl_context_info_handler(1982) [C6.1:2][0x10b9786e0] Client handshake state: TLS client read_server_hello
2020-02-17 16:31:59.332596 +0800 putong boringssl_context_add_handshake_message_pending(577) [C6.1:2][0x10b9786e0] Adding message(2)
2020-02-17 16:31:59.332600 +0800 putong boringssl_session_handshake_incomplete(191) [C6.1:2][0x10b9786e0] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.332601 +0800 putong boringssl_session_handshake_incomplete(191) [C6.1:2][0x10b9786e0] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.332616 +0800 putong boringssl_session_handshake_incomplete(191) [C6.1:2][0x10b9786e0] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.332616 +0800 putong boringssl_session_handshake_incomplete(191) [C6.1:2][0x10b9786e0] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.337976 +0800 putong boringssl_context_message_handler(2257) [C1.1:2][0x10b929110] Reading SSL3_RT_HANDSHAKE 122 bytes
2020-02-17 16:31:59.337977 +0800 putong boringssl_context_info_handler(1982) [C1.1:2][0x10b929110] Client handshake state: TLS 1.3 client read_hello_retry_request
2020-02-17 16:31:59.337981 +0800 putong boringssl_context_add_handshake_message_pending(577) [C1.1:2][0x10b929110] Adding message(2)
2020-02-17 16:31:59.337982 +0800 putong boringssl_context_message_handler(2257) [C1.1:2][0x10b929110] Writing SSL3_RT_CHANGE_CIPHER_SPEC 1 bytes
2020-02-17 16:31:59.337984 +0800 putong boringssl_context_info_handler(1982) [C1.1:2][0x10b929110] Client handshake state: TLS 1.3 client read_server_hello
2020-02-17 16:31:59.338076 +0800 putong boringssl_context_info_handler(1982) [C1.1:2][0x10b929110] Client handshake state: TLS 1.3 client read_encrypted_extensions
2020-02-17 16:31:59.338078 +0800 putong boringssl_session_handshake_incomplete(191) [C1.1:2][0x10b929110] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.338274 +0800 putong boringssl_session_handshake_incomplete(191) [C1.1:2][0x10b929110] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.339294 +0800 putong boringssl_session_handshake_incomplete(191) [C1.1:2][0x10b929110] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.341285 +0800 putong boringssl_context_message_handler(2257) [C1.1:2][0x10b929110] Reading SSL3_RT_HANDSHAKE 15 bytes
2020-02-17 16:31:59.341289 +0800 putong boringssl_context_info_handler(1982) [C1.1:2][0x10b929110] Client handshake state: TLS 1.3 client read_certificate_request
2020-02-17 16:31:59.341290 +0800 putong boringssl_context_message_handler(2257) [C1.1:2][0x10b929110] Reading SSL3_RT_HANDSHAKE 4345 bytes
2020-02-17 16:31:59.341296 +0800 putong boringssl_context_info_handler(1982) [C1.1:2][0x10b929110] Client handshake state: TLS 1.3 client read_server_certificate
2020-02-17 16:31:59.341310 +0800 putong boringssl_context_message_handler(2257) [C1.1:2][0x10b929110] Reading SSL3_RT_HANDSHAKE 264 bytes
2020-02-17 16:31:59.341310 +0800 putong boringssl_context_info_handler(1982) [C1.1:2][0x10b929110] Client handshake state: TLS 1.3 client read_server_certificate_verify
2020-02-17 16:31:59.341375 +0800 putong boringssl_context_copy_peer_sct_list(1002) [C1.1:2][0x10b929110] SSL_get0_signed_cert_timestamp_list returned no SCT extension data
2020-02-17 16:31:59.341389 +0800 putong boringssl_helper_create_sec_trust_with_certificates(607) [C1.1:2][0x10b929110] SecTrustCreateWithCertificates result: 0
2020-02-17 16:31:59.341396 +0800 putong boringssl_helper_create_sec_trust_with_certificates(614) [C1.1:2][0x10b929110] No TLS-provided OCSP response
2020-02-17 16:31:59.341397 +0800 putong boringssl_helper_create_sec_trust_with_certificates(621) [C1.1:2][0x10b929110] No TLS-provided SCTs
2020-02-17 16:31:59.341442 +0800 putong boringssl_context_certificate_verify_callback(2070) [C1.1:2][0x10b929110] Asyncing for verify block
2020-02-17 16:31:59.341451 +0800 putong boringssl_session_handshake_incomplete(191) [C1.1:2][0x10b929110] Early handshake return caused by SSL_ERROR_WANT_CERTIFICATE_VERIFY [16]
2020-02-17 16:31:59.341456 +0800 putong Connection 1: asked to evaluate TLS Trust
2020-02-17 16:31:59.345477 +0800 putong Task <69448DEA-7CB0-47E5-84A0-66DB49D8EB62>.<1> auth completion disp=0 cred=0x283d65940
2020-02-17 16:31:59.345951 +0800 locationd {"msg":"reduceFreePages", "path":"\/var\/root\/Library\/Caches\/locationd\/sensorRecorder_encryptedC.db", "page_count":16, "freelist_count":0, "loadFactor":"1.000000"}
2020-02-17 16:31:59.345953 +0800 locationd {"msg":"reduceFreePages", "event":"elapsed", "begin_mach":173753245120, "end_mach":173753246152, "elapsed_s":"0.000043000"}
2020-02-17 16:31:59.347753 +0800 trustd Failed to read from permanent storage at '/Library/Keychains/com.apple.security.exception_reset_counter.plist' or the data is bad. Defaulting to value 0.
2020-02-17 16:31:59.347795 +0800 putong Connection 1: TLS Trust result 0
2020-02-17 16:31:59.347809 +0800 putong boringssl_context_certificate_verify_callback_block_invoke_3(2079) [C1.1:2][0x10b929110] Returning from verify block
2020-02-17 16:31:59.347811 +0800 putong boringssl_context_certificate_verify_callback(2046) [C1.1:2][0x10b929110] Setting trust result to ssl_verify_ok
2020-02-17 16:31:59.347938 +0800 putong boringssl_context_info_handler(1982) [C1.1:2][0x10b929110] Client handshake state: TLS 1.3 client read_server_finished
2020-02-17 16:31:59.347939 +0800 putong boringssl_context_message_handler(2257) [C1.1:2][0x10b929110] Reading SSL3_RT_HANDSHAKE 36 bytes
2020-02-17 16:31:59.347954 +0800 putong boringssl_context_info_handler(1982) [C1.1:2][0x10b929110] Client handshake state: TLS 1.3 client send_end_of_early_data
2020-02-17 16:31:59.347954 +0800 putong boringssl_context_info_handler(1982) [C1.1:2][0x10b929110] Client handshake state: TLS 1.3 client complete_second_flight
2020-02-17 16:31:59.347954 +0800 putong boringssl_context_info_handler(1982) [C1.1:2][0x10b929110] Client handshake state: TLS 1.3 client send_client_certificate
2020-02-17 16:31:59.347958 +0800 putong boringssl_context_message_handler(2257) [C1.1:2][0x10b929110] Writing SSL3_RT_HANDSHAKE 36 bytes
2020-02-17 16:31:59.347966 +0800 putong boringssl_context_info_handler(1982) [C1.1:2][0x10b929110] Client handshake state: TLS 1.3 client done
2020-02-17 16:31:59.348042 +0800 putong boringssl_context_info_handler(1982) [C1.1:2][0x10b929110] Client handshake state: TLS client finish_client_handshake
2020-02-17 16:31:59.348045 +0800 putong boringssl_context_info_handler(1982) [C1.1:2][0x10b929110] Client handshake state: TLS client done
2020-02-17 16:31:59.348093 +0800 putong boringssl_context_copy_peer_sct_list(1002) [C1.1:2][0x10b929110] SSL_get0_signed_cert_timestamp_list returned no SCT extension data
2020-02-17 16:31:59.348104 +0800 putong boringssl_helper_create_sec_trust_with_certificates(621) [C1.1:2][0x10b929110] No TLS-provided SCTs
2020-02-17 16:31:59.348104 +0800 putong boringssl_helper_create_sec_trust_with_certificates(614) [C1.1:2][0x10b929110] No TLS-provided OCSP response
2020-02-17 16:31:59.348104 +0800 putong boringssl_helper_create_sec_trust_with_certificates(607) [C1.1:2][0x10b929110] SecTrustCreateWithCertificates result: 0
2020-02-17 16:31:59.348162 +0800 putong boringssl_context_add_handshake_message_pending(577) [C1.1:2][0x10b929110] Adding message(20)
2020-02-17 16:31:59.348164 +0800 putong boringssl_context_info_handler(1973) [C1.1:2][0x10b929110] Client handshake done
2020-02-17 16:31:59.348174 +0800 putong nw_protocol_boringssl_signal_connected(701) [C1.1:2][0x10b929110] TLS connected [version(0x0304) ciphersuite(0x1301) group(0x001d) peer_key(0x0804) alpn(h2) resumed(0) offered_ticket(0) false_started(0) ocsp(0) sct(0)]
2020-02-17 16:31:59.348185 +0800 putong nw_flow_connected [C1.1 IPv4#a620a233:443 in_progress channel-flow (satisfied (Path is satisfied), interface: pdp_ip0, ipv4, ipv6, dns, expensive)] Output protocol connected
2020-02-17 16:31:59.348207 +0800 putong nw_connection_report_state_with_handler_on_nw_queue [C1] reporting state ready
2020-02-17 16:31:59.348227 +0800 putong Connection 1: connected successfully
2020-02-17 16:31:59.348233 +0800 putong Connection 1: TLS handshake complete
2020-02-17 16:31:59.348285 +0800 putong Connection 1: ready C(Y) E(Y)
2020-02-17 16:31:59.348345 +0800 putong new connection to <private> config 0x283f1f780
2020-02-17 16:31:59.348434 +0800 putong Task <69448DEA-7CB0-47E5-84A0-66DB49D8EB62>.<1> now using Connection 1
2020-02-17 16:31:59.348443 +0800 putong Connection 1: received viability advisory(Y)
2020-02-17 16:31:59.348527 +0800 putong Task <69448DEA-7CB0-47E5-84A0-66DB49D8EB62>.<1> sent request, body N 0
2020-02-17 16:31:59.348995 +0800 putong tcp_output [C3.2:3] flags=[S] seq=1945962549, ack=0, win=65535 state=SYN_SENT rcv_nxt=0, snd_una=1945962549
2020-02-17 16:31:59.349005 +0800 putong tcp_input [C8.1:3] flags=[S.] seq=1717659748, ack=988079008, win=28960 state=SYN_SENT rcv_nxt=0, snd_una=988079007
2020-02-17 16:31:59.349018 +0800 putong nw_flow_connected [C8.1 IPv4#aea2b038:443 in_progress channel-flow (satisfied (Path is satisfied), interface: pdp_ip0, ipv4, ipv6, dns, expensive)] Transport protocol connected
2020-02-17 16:31:59.349045 +0800 putong boringssl_context_set_handshake_config(1470) [0x10b98ac20] set tls_handshake_config_standard
2020-02-17 16:31:59.349045 +0800 putong boringssl_context_set_max_version(308) [0x10b98ac20] set 0x0304
2020-02-17 16:31:59.349045 +0800 putong boringssl_context_set_min_version(324) [0x10b98ac20] set 0x0301
2020-02-17 16:31:59.349051 +0800 putong boringssl_context_set_cipher_suites(842) [0x10b98ac20] Ciphersuite string: TLS_AES_128_GCM_SHA256:TLS_AES_256_GCM_SHA384:TLS_CHACHA20_POLY1305_SHA256:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-SHA384:ECDHE-ECDSA-AES128-SHA256:ECDHE-ECDSA-AES256-SHA:ECDHE-ECDSA-AES128-SHA:ECDHE-ECDSA-CHACHA20-POLY1305:ECDHE-RSA-AES256-GCM-SHA384:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-RSA-AES256-SHA384:ECDHE-RSA-AES128-SHA256:ECDHE-RSA-AES256-SHA:ECDHE-RSA-AES128-SHA:ECDHE-RSA-CHACHA20-POLY1305:AES256-GCM-SHA384:AES128-GCM-SHA256:AES256-SHA256:AES128-SHA256:AES256-SHA:AES128-SHA:ECDHE-ECDSA-AES128-SHA:ECDHE-ECDSA-AES256-SHA:ECDHE-RSA-AES128-SHA:ECDHE-RSA-AES256-SHA:AES256-SHA:AES128-SHA:ECDHE-ECDSA-DES-CBC3-SHA:ECDHE-RSA-DES-CBC3-SHA:DES-CBC3-SHA
2020-02-17 16:31:59.349067 +0800 putong boringssl_context_set_remote_address(2554) [0x10b98ac20] Saving remote IPv4 address
2020-02-17 16:31:59.349075 +0800 putong boringssl_session_install_association_state(1297) [0x10b98ac20] Client session cache miss
2020-02-17 16:31:59.349076 +0800 putong boringssl_session_set_peer_hostname(1189) [0x10b98ac20] SNI <private>
2020-02-17 16:31:59.349080 +0800 putong boringssl_context_set_min_version(324) [C8.1:2][0x10b98ac20] set 0x0301
2020-02-17 16:31:59.349081 +0800 putong boringssl_context_set_session_ticket_enabled(439) [C8.1:2][0x10b98ac20] set false
2020-02-17 16:31:59.349081 +0800 putong boringssl_context_set_ats_enforced(1320) [C8.1:2][0x10b98ac20] set false
2020-02-17 16:31:59.349081 +0800 putong boringssl_context_set_enforce_ev(399) [C8.1:2][0x10b98ac20] set false
2020-02-17 16:31:59.349081 +0800 putong boringssl_context_set_false_start(409) [C8.1:2][0x10b98ac20] set false
2020-02-17 16:31:59.349082 +0800 putong boringssl_context_set_ats_minimum_signature_algorithm(1348) [C8.1:2][0x10b98ac20] set 0
2020-02-17 16:31:59.349082 +0800 putong boringssl_context_set_ats_minimum_ecdsa_key_size(1338) [C8.1:2][0x10b98ac20] set 0
2020-02-17 16:31:59.349082 +0800 putong boringssl_context_set_ats_minimum_rsa_key_size(1329) [C8.1:2][0x10b98ac20] set 0
2020-02-17 16:31:59.349085 +0800 putong boringssl_session_set_peer_hostname(1189) [C8.1:2][0x10b98ac20] SNI <private>
2020-02-17 16:31:59.349097 +0800 putong boringssl_context_set_cipher_suites(842) [C8.1:2][0x10b98ac20] Ciphersuite string: TLS_AES_128_GCM_SHA256:TLS_AES_256_GCM_SHA384:TLS_CHACHA20_POLY1305_SHA256:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-SHA384:ECDHE-ECDSA-AES128-SHA256:ECDHE-ECDSA-AES256-SHA:ECDHE-ECDSA-AES128-SHA:ECDHE-ECDSA-CHACHA20-POLY1305:ECDHE-RSA-AES256-GCM-SHA384:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-RSA-AES256-SHA384:ECDHE-RSA-AES128-SHA256:ECDHE-RSA-AES256-SHA:ECDHE-RSA-AES128-SHA:ECDHE-RSA-CHACHA20-POLY1305:AES256-GCM-SHA384:AES128-GCM-SHA256:AES256-SHA256:AES128-SHA256:AES256-SHA:AES128-SHA:ECDHE-ECDSA-AES128-SHA:ECDHE-ECDSA-AES256-SHA:ECDHE-RSA-AES128-SHA:ECDHE-RSA-AES256-SHA:AES256-SHA:AES128-SHA:ECDHE-ECDSA-DES-CBC3-SHA:ECDHE-RSA-DES-CBC3-SHA:DES-CBC3-SHA
2020-02-17 16:31:59.349118 +0800 putong nw_protocol_boringssl_begin_connection(497) [C8.1:2][0x10b98ac20] early data disabled
2020-02-17 16:31:59.349119 +0800 putong boringssl_context_info_handler(1969) [C8.1:2][0x10b98ac20] Client handshake started
2020-02-17 16:31:59.349153 +0800 putong boringssl_context_message_handler(2257) [C8.1:2][0x10b98ac20] Writing SSL3_RT_HANDSHAKE 512 bytes
2020-02-17 16:31:59.349153 +0800 putong boringssl_context_info_handler(1982) [C8.1:2][0x10b98ac20] Client handshake state: TLS client enter_early_data
2020-02-17 16:31:59.349154 +0800 putong boringssl_context_add_handshake_message_pending(577) [C8.1:2][0x10b98ac20] Adding message(1)
2020-02-17 16:31:59.349159 +0800 putong boringssl_context_info_handler(1982) [C8.1:2][0x10b98ac20] Client handshake state: TLS client read_server_hello
2020-02-17 16:31:59.349160 +0800 putong boringssl_context_add_handshake_message_pending(577) [C8.1:2][0x10b98ac20] Adding message(2)
2020-02-17 16:31:59.349164 +0800 putong boringssl_session_handshake_incomplete(191) [C8.1:2][0x10b98ac20] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.349164 +0800 putong boringssl_session_handshake_incomplete(191) [C8.1:2][0x10b98ac20] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.349448 +0800 putong tcp_output [C4.2:3] flags=[S] seq=869982697, ack=0, win=65535 state=SYN_SENT rcv_nxt=0, snd_una=869982697
2020-02-17 16:31:59.349469 +0800 putong boringssl_session_handshake_incomplete(191) [C8.1:2][0x10b98ac20] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.349471 +0800 putong boringssl_session_handshake_incomplete(191) [C8.1:2][0x10b98ac20] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.349472 +0800 putong tcp_input [C7.1:3] flags=[S.] seq=2790474093, ack=795490964, win=28960 state=SYN_SENT rcv_nxt=0, snd_una=795490963
2020-02-17 16:31:59.349482 +0800 putong nw_flow_connected [C7.1 IPv4#6f04fc1d:443 in_progress channel-flow (satisfied (Path is satisfied), interface: pdp_ip0, ipv4, ipv6, dns, expensive)] Transport protocol connected
2020-02-17 16:31:59.349503 +0800 putong boringssl_context_set_max_version(308) [0x10b98a3d0] set 0x0304
2020-02-17 16:31:59.349503 +0800 putong boringssl_context_set_min_version(324) [0x10b98a3d0] set 0x0301
2020-02-17 16:31:59.349503 +0800 putong boringssl_context_set_handshake_config(1470) [0x10b98a3d0] set tls_handshake_config_standard
2020-02-17 16:31:59.349509 +0800 putong boringssl_context_set_cipher_suites(842) [0x10b98a3d0] Ciphersuite string: TLS_AES_128_GCM_SHA256:TLS_AES_256_GCM_SHA384:TLS_CHACHA20_POLY1305_SHA256:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-SHA384:ECDHE-ECDSA-AES128-SHA256:ECDHE-ECDSA-AES256-SHA:ECDHE-ECDSA-AES128-SHA:ECDHE-ECDSA-CHACHA20-POLY1305:ECDHE-RSA-AES256-GCM-SHA384:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-RSA-AES256-SHA384:ECDHE-RSA-AES128-SHA256:ECDHE-RSA-AES256-SHA:ECDHE-RSA-AES128-SHA:ECDHE-RSA-CHACHA20-POLY1305:AES256-GCM-SHA384:AES128-GCM-SHA256:AES256-SHA256:AES128-SHA256:AES256-SHA:AES128-SHA:ECDHE-ECDSA-AES128-SHA:ECDHE-ECDSA-AES256-SHA:ECDHE-RSA-AES128-SHA:ECDHE-RSA-AES256-SHA:AES256-SHA:AES128-SHA:ECDHE-ECDSA-DES-CBC3-SHA:ECDHE-RSA-DES-CBC3-SHA:DES-CBC3-SHA
2020-02-17 16:31:59.349525 +0800 putong boringssl_context_set_remote_address(2554) [0x10b98a3d0] Saving remote IPv4 address
2020-02-17 16:31:59.349529 +0800 putong boringssl_session_install_association_state(1297) [0x10b98a3d0] Client session cache miss
2020-02-17 16:31:59.349536 +0800 putong boringssl_session_set_peer_hostname(1189) [0x10b98a3d0] SNI <private>
2020-02-17 16:31:59.349539 +0800 putong boringssl_context_set_min_version(324) [C7.1:2][0x10b98a3d0] set 0x0301
2020-02-17 16:31:59.349539 +0800 putong boringssl_context_set_enforce_ev(399) [C7.1:2][0x10b98a3d0] set false
2020-02-17 16:31:59.349539 +0800 putong boringssl_context_set_false_start(409) [C7.1:2][0x10b98a3d0] set false
2020-02-17 16:31:59.349539 +0800 putong boringssl_context_set_session_ticket_enabled(439) [C7.1:2][0x10b98a3d0] set false
2020-02-17 16:31:59.349540 +0800 putong boringssl_context_set_ats_minimum_rsa_key_size(1329) [C7.1:2][0x10b98a3d0] set 0
2020-02-17 16:31:59.349540 +0800 putong boringssl_context_set_ats_enforced(1320) [C7.1:2][0x10b98a3d0] set false
2020-02-17 16:31:59.349545 +0800 putong boringssl_context_set_ats_minimum_ecdsa_key_size(1338) [C7.1:2][0x10b98a3d0] set 0
2020-02-17 16:31:59.349546 +0800 putong boringssl_context_set_ats_minimum_signature_algorithm(1348) [C7.1:2][0x10b98a3d0] set 0
2020-02-17 16:31:59.349549 +0800 putong boringssl_session_set_peer_hostname(1189) [C7.1:2][0x10b98a3d0] SNI <private>
2020-02-17 16:31:59.349559 +0800 putong boringssl_context_set_cipher_suites(842) [C7.1:2][0x10b98a3d0] Ciphersuite string: TLS_AES_128_GCM_SHA256:TLS_AES_256_GCM_SHA384:TLS_CHACHA20_POLY1305_SHA256:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-SHA384:ECDHE-ECDSA-AES128-SHA256:ECDHE-ECDSA-AES256-SHA:ECDHE-ECDSA-AES128-SHA:ECDHE-ECDSA-CHACHA20-POLY1305:ECDHE-RSA-AES256-GCM-SHA384:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-RSA-AES256-SHA384:ECDHE-RSA-AES128-SHA256:ECDHE-RSA-AES256-SHA:ECDHE-RSA-AES128-SHA:ECDHE-RSA-CHACHA20-POLY1305:AES256-GCM-SHA384:AES128-GCM-SHA256:AES256-SHA256:AES128-SHA256:AES256-SHA:AES128-SHA:ECDHE-ECDSA-AES128-SHA:ECDHE-ECDSA-AES256-SHA:ECDHE-RSA-AES128-SHA:ECDHE-RSA-AES256-SHA:AES256-SHA:AES128-SHA:ECDHE-ECDSA-DES-CBC3-SHA:ECDHE-RSA-DES-CBC3-SHA:DES-CBC3-SHA
2020-02-17 16:31:59.349580 +0800 putong nw_protocol_boringssl_begin_connection(497) [C7.1:2][0x10b98a3d0] early data disabled
2020-02-17 16:31:59.349581 +0800 putong boringssl_context_info_handler(1969) [C7.1:2][0x10b98a3d0] Client handshake started
2020-02-17 16:31:59.349611 +0800 putong boringssl_context_message_handler(2257) [C7.1:2][0x10b98a3d0] Writing SSL3_RT_HANDSHAKE 512 bytes
2020-02-17 16:31:59.349612 +0800 putong boringssl_context_info_handler(1982) [C7.1:2][0x10b98a3d0] Client handshake state: TLS client enter_early_data
2020-02-17 16:31:59.349613 +0800 putong boringssl_context_add_handshake_message_pending(577) [C7.1:2][0x10b98a3d0] Adding message(1)
2020-02-17 16:31:59.349627 +0800 putong boringssl_context_info_handler(1982) [C7.1:2][0x10b98a3d0] Client handshake state: TLS client read_server_hello
2020-02-17 16:31:59.349628 +0800 putong boringssl_context_add_handshake_message_pending(577) [C7.1:2][0x10b98a3d0] Adding message(2)
2020-02-17 16:31:59.349632 +0800 putong boringssl_session_handshake_incomplete(191) [C7.1:2][0x10b98a3d0] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.349632 +0800 putong boringssl_session_handshake_incomplete(191) [C7.1:2][0x10b98a3d0] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.349668 +0800 putong boringssl_session_handshake_incomplete(191) [C7.1:2][0x10b98a3d0] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.349668 +0800 putong boringssl_session_handshake_incomplete(191) [C7.1:2][0x10b98a3d0] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.373296 +0800 putong boringssl_session_handshake_incomplete(191) [C5.1:2][0x10b838af0] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.373296 +0800 putong boringssl_session_handshake_incomplete(191) [C5.1:2][0x10b838af0] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.376422 +0800 putong boringssl_context_message_handler(2257) [C5.1:2][0x10b838af0] Reading SSL3_RT_HANDSHAKE 108 bytes
2020-02-17 16:31:59.376445 +0800 putong boringssl_context_info_handler(1982) [C5.1:2][0x10b838af0] Client handshake state: TLS client read_server_certificate
2020-02-17 16:31:59.376446 +0800 putong boringssl_context_add_handshake_message_pending(577) [C5.1:2][0x10b838af0] Adding message(2)
2020-02-17 16:31:59.376447 +0800 putong boringssl_session_handshake_incomplete(191) [C5.1:2][0x10b838af0] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.378159 +0800 putong boringssl_session_handshake_incomplete(191) [C5.1:2][0x10b838af0] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.387365 +0800 putong boringssl_context_message_handler(2257) [C5.1:2][0x10b838af0] Reading SSL3_RT_HANDSHAKE 4911 bytes
2020-02-17 16:31:59.387375 +0800 putong boringssl_context_info_handler(1982) [C5.1:2][0x10b838af0] Client handshake state: TLS client read_certificate_status
2020-02-17 16:31:59.387376 +0800 putong boringssl_context_info_handler(1982) [C5.1:2][0x10b838af0] Client handshake state: TLS client verify_server_certificate
2020-02-17 16:31:59.387444 +0800 putong boringssl_context_copy_peer_sct_list(1002) [C5.1:2][0x10b838af0] SSL_get0_signed_cert_timestamp_list returned no SCT extension data
2020-02-17 16:31:59.387468 +0800 putong boringssl_helper_create_sec_trust_with_certificates(614) [C5.1:2][0x10b838af0] No TLS-provided OCSP response
2020-02-17 16:31:59.387468 +0800 putong boringssl_helper_create_sec_trust_with_certificates(607) [C5.1:2][0x10b838af0] SecTrustCreateWithCertificates result: 0
2020-02-17 16:31:59.387469 +0800 putong boringssl_helper_create_sec_trust_with_certificates(621) [C5.1:2][0x10b838af0] No TLS-provided SCTs
2020-02-17 16:31:59.387510 +0800 putong boringssl_context_certificate_verify_callback(2070) [C5.1:2][0x10b838af0] Asyncing for verify block
2020-02-17 16:31:59.387512 +0800 putong boringssl_session_handshake_incomplete(191) [C5.1:2][0x10b838af0] Early handshake return caused by SSL_ERROR_WANT_CERTIFICATE_VERIFY [16]
2020-02-17 16:31:59.387517 +0800 putong Connection 5: asked to evaluate TLS Trust
2020-02-17 16:31:59.390594 +0800 putong Task <0993B2F7-152E-4B20-9704-1BC0BD863B55>.<1> auth completion disp=0 cred=0x283d6cff0
2020-02-17 16:31:59.393655 +0800 trustd Failed to read from permanent storage at '/Library/Keychains/com.apple.security.exception_reset_counter.plist' or the data is bad. Defaulting to value 0.
2020-02-17 16:31:59.393698 +0800 putong Connection 5: TLS Trust result 0
2020-02-17 16:31:59.393704 +0800 putong boringssl_context_certificate_verify_callback_block_invoke_3(2079) [C5.1:2][0x10b838af0] Returning from verify block
2020-02-17 16:31:59.393706 +0800 putong boringssl_context_certificate_verify_callback(2046) [C5.1:2][0x10b838af0] Setting trust result to ssl_verify_ok
2020-02-17 16:31:59.393707 +0800 putong boringssl_context_info_handler(1982) [C5.1:2][0x10b838af0] Client handshake state: TLS client read_server_key_exchange
2020-02-17 16:31:59.393708 +0800 putong boringssl_context_message_handler(2257) [C5.1:2][0x10b838af0] Reading SSL3_RT_HANDSHAKE 333 bytes
2020-02-17 16:31:59.393836 +0800 putong boringssl_context_info_handler(1982) [C5.1:2][0x10b838af0] Client handshake state: TLS client read_certificate_request
2020-02-17 16:31:59.393840 +0800 putong boringssl_context_message_handler(2257) [C5.1:2][0x10b838af0] Reading SSL3_RT_HANDSHAKE 4 bytes
2020-02-17 16:31:59.393841 +0800 putong boringssl_context_info_handler(1982) [C5.1:2][0x10b838af0] Client handshake state: TLS client send_client_certificate
2020-02-17 16:31:59.393841 +0800 putong boringssl_context_info_handler(1982) [C5.1:2][0x10b838af0] Client handshake state: TLS client read_server_hello_done
2020-02-17 16:31:59.393841 +0800 putong boringssl_context_add_handshake_message_pending(577) [C5.1:2][0x10b838af0] Adding message(14)
2020-02-17 16:31:59.393842 +0800 putong boringssl_context_info_handler(1982) [C5.1:2][0x10b838af0] Client handshake state: TLS client send_client_key_exchange
2020-02-17 16:31:59.394231 +0800 putong boringssl_context_message_handler(2257) [C5.1:2][0x10b838af0] Writing SSL3_RT_HANDSHAKE 70 bytes
2020-02-17 16:31:59.394237 +0800 putong boringssl_context_info_handler(1982) [C5.1:2][0x10b838af0] Client handshake state: TLS client send_client_certificate_verify
2020-02-17 16:31:59.394246 +0800 putong boringssl_context_info_handler(1982) [C5.1:2][0x10b838af0] Client handshake state: TLS client send_client_finished
2020-02-17 16:31:59.394247 +0800 putong boringssl_context_message_handler(2257) [C5.1:2][0x10b838af0] Writing SSL3_RT_CHANGE_CIPHER_SPEC 1 bytes
2020-02-17 16:31:59.394264 +0800 putong boringssl_context_message_handler(2257) [C5.1:2][0x10b838af0] Writing SSL3_RT_HANDSHAKE 16 bytes
2020-02-17 16:31:59.394265 +0800 putong boringssl_context_info_handler(1982) [C5.1:2][0x10b838af0] Client handshake state: TLS client finish_flight
2020-02-17 16:31:59.394282 +0800 putong boringssl_context_info_handler(1982) [C5.1:2][0x10b838af0] Client handshake state: TLS client process_change_cipher_spec
2020-02-17 16:31:59.394282 +0800 putong boringssl_context_info_handler(1982) [C5.1:2][0x10b838af0] Client handshake state: TLS client read_session_ticket
2020-02-17 16:31:59.394284 +0800 putong boringssl_session_handshake_incomplete(191) [C5.1:2][0x10b838af0] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.394284 +0800 putong boringssl_session_handshake_incomplete(191) [C5.1:2][0x10b838af0] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.412276 +0800 putong boringssl_session_handshake_incomplete(191) [C6.1:2][0x10b9786e0] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.412277 +0800 putong boringssl_session_handshake_incomplete(191) [C6.1:2][0x10b9786e0] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.413208 +0800 putong boringssl_context_message_handler(2257) [C6.1:2][0x10b9786e0] Reading SSL3_RT_HANDSHAKE 108 bytes
2020-02-17 16:31:59.413213 +0800 putong boringssl_context_info_handler(1982) [C6.1:2][0x10b9786e0] Client handshake state: TLS client read_server_certificate
2020-02-17 16:31:59.413214 +0800 putong boringssl_context_add_handshake_message_pending(577) [C6.1:2][0x10b9786e0] Adding message(2)
2020-02-17 16:31:59.413217 +0800 putong boringssl_session_handshake_incomplete(191) [C6.1:2][0x10b9786e0] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.414581 +0800 putong boringssl_session_handshake_incomplete(191) [C6.1:2][0x10b9786e0] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.416285 +0800 putong boringssl_context_message_handler(2257) [C6.1:2][0x10b9786e0] Reading SSL3_RT_HANDSHAKE 4911 bytes
2020-02-17 16:31:59.416296 +0800 putong boringssl_context_info_handler(1982) [C6.1:2][0x10b9786e0] Client handshake state: TLS client read_certificate_status
2020-02-17 16:31:59.416296 +0800 putong boringssl_context_info_handler(1982) [C6.1:2][0x10b9786e0] Client handshake state: TLS client verify_server_certificate
2020-02-17 16:31:59.416346 +0800 putong boringssl_context_copy_peer_sct_list(1002) [C6.1:2][0x10b9786e0] SSL_get0_signed_cert_timestamp_list returned no SCT extension data
2020-02-17 16:31:59.416362 +0800 putong boringssl_helper_create_sec_trust_with_certificates(621) [C6.1:2][0x10b9786e0] No TLS-provided SCTs
2020-02-17 16:31:59.416362 +0800 putong boringssl_helper_create_sec_trust_with_certificates(614) [C6.1:2][0x10b9786e0] No TLS-provided OCSP response
2020-02-17 16:31:59.416362 +0800 putong boringssl_helper_create_sec_trust_with_certificates(607) [C6.1:2][0x10b9786e0] SecTrustCreateWithCertificates result: 0
2020-02-17 16:31:59.416384 +0800 putong boringssl_context_certificate_verify_callback(2070) [C6.1:2][0x10b9786e0] Asyncing for verify block
2020-02-17 16:31:59.416387 +0800 putong boringssl_session_handshake_incomplete(191) [C6.1:2][0x10b9786e0] Early handshake return caused by SSL_ERROR_WANT_CERTIFICATE_VERIFY [16]
2020-02-17 16:31:59.416390 +0800 putong Connection 6: asked to evaluate TLS Trust
2020-02-17 16:31:59.417958 +0800 putong Task <F843BD33-FA2B-4C27-9E60-0F5801769793>.<2> auth completion disp=0 cred=0x283d65e50
2020-02-17 16:31:59.420634 +0800 trustd Failed to read from permanent storage at '/Library/Keychains/com.apple.security.exception_reset_counter.plist' or the data is bad. Defaulting to value 0.
2020-02-17 16:31:59.420706 +0800 putong Connection 6: TLS Trust result 0
2020-02-17 16:31:59.420711 +0800 putong boringssl_context_certificate_verify_callback_block_invoke_3(2079) [C6.1:2][0x10b9786e0] Returning from verify block
2020-02-17 16:31:59.420717 +0800 putong boringssl_context_certificate_verify_callback(2046) [C6.1:2][0x10b9786e0] Setting trust result to ssl_verify_ok
2020-02-17 16:31:59.420718 +0800 putong boringssl_context_info_handler(1982) [C6.1:2][0x10b9786e0] Client handshake state: TLS client read_server_key_exchange
2020-02-17 16:31:59.420722 +0800 putong boringssl_context_message_handler(2257) [C6.1:2][0x10b9786e0] Reading SSL3_RT_HANDSHAKE 333 bytes
2020-02-17 16:31:59.420851 +0800 putong boringssl_context_info_handler(1982) [C6.1:2][0x10b9786e0] Client handshake state: TLS client read_certificate_request
2020-02-17 16:31:59.420855 +0800 putong boringssl_context_message_handler(2257) [C6.1:2][0x10b9786e0] Reading SSL3_RT_HANDSHAKE 4 bytes
2020-02-17 16:31:59.420855 +0800 putong boringssl_context_info_handler(1982) [C6.1:2][0x10b9786e0] Client handshake state: TLS client read_server_hello_done
2020-02-17 16:31:59.420856 +0800 putong boringssl_context_add_handshake_message_pending(577) [C6.1:2][0x10b9786e0] Adding message(14)
2020-02-17 16:31:59.420856 +0800 putong boringssl_context_info_handler(1982) [C6.1:2][0x10b9786e0] Client handshake state: TLS client send_client_certificate
2020-02-17 16:31:59.420859 +0800 putong boringssl_context_info_handler(1982) [C6.1:2][0x10b9786e0] Client handshake state: TLS client send_client_key_exchange
2020-02-17 16:31:59.421169 +0800 putong boringssl_context_message_handler(2257) [C6.1:2][0x10b9786e0] Writing SSL3_RT_HANDSHAKE 70 bytes
2020-02-17 16:31:59.421175 +0800 putong boringssl_context_info_handler(1982) [C6.1:2][0x10b9786e0] Client handshake state: TLS client send_client_certificate_verify
2020-02-17 16:31:59.421176 +0800 putong boringssl_context_info_handler(1982) [C6.1:2][0x10b9786e0] Client handshake state: TLS client send_client_finished
2020-02-17 16:31:59.421178 +0800 putong boringssl_context_message_handler(2257) [C6.1:2][0x10b9786e0] Writing SSL3_RT_CHANGE_CIPHER_SPEC 1 bytes
2020-02-17 16:31:59.421195 +0800 putong boringssl_context_message_handler(2257) [C6.1:2][0x10b9786e0] Writing SSL3_RT_HANDSHAKE 16 bytes
2020-02-17 16:31:59.421196 +0800 putong boringssl_context_info_handler(1982) [C6.1:2][0x10b9786e0] Client handshake state: TLS client finish_flight
2020-02-17 16:31:59.421216 +0800 putong boringssl_context_info_handler(1982) [C6.1:2][0x10b9786e0] Client handshake state: TLS client read_session_ticket
2020-02-17 16:31:59.421216 +0800 putong boringssl_context_info_handler(1982) [C6.1:2][0x10b9786e0] Client handshake state: TLS client process_change_cipher_spec
2020-02-17 16:31:59.421219 +0800 putong boringssl_session_handshake_incomplete(191) [C6.1:2][0x10b9786e0] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.421219 +0800 putong boringssl_session_handshake_incomplete(191) [C6.1:2][0x10b9786e0] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.456351 +0800 putong boringssl_context_message_handler(2257) [C7.1:2][0x10b98a3d0] Reading SSL3_RT_HANDSHAKE 93 bytes
2020-02-17 16:31:59.456366 +0800 putong boringssl_context_info_handler(1982) [C7.1:2][0x10b98a3d0] Client handshake state: TLS client read_server_certificate
2020-02-17 16:31:59.456367 +0800 putong boringssl_context_add_handshake_message_pending(577) [C7.1:2][0x10b98a3d0] Adding message(2)
2020-02-17 16:31:59.456370 +0800 putong boringssl_session_handshake_incomplete(191) [C7.1:2][0x10b98a3d0] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.456374 +0800 putong boringssl_session_handshake_incomplete(191) [C7.1:2][0x10b98a3d0] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.456376 +0800 putong boringssl_session_handshake_incomplete(191) [C7.1:2][0x10b98a3d0] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.458498 +0800 kernel Quota update for stream kGPU_FBToDisplay. PrevSize: 0x800000 newSize: 0x0 totalAssignedCache: 0x8ae400
2020-02-17 16:31:59.458509 +0800 kernel Quota update for stream kGPU_Reads. PrevSize: 0x800000 newSize: 0x0 totalAssignedCache: 0xae400
2020-02-17 16:31:59.459119 +0800 putong boringssl_session_handshake_incomplete(191) [C7.1:2][0x10b98a3d0] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.467287 +0800 putong boringssl_context_message_handler(2257) [C7.1:2][0x10b98a3d0] Reading SSL3_RT_HANDSHAKE 4911 bytes
2020-02-17 16:31:59.467304 +0800 putong boringssl_context_info_handler(1982) [C7.1:2][0x10b98a3d0] Client handshake state: TLS client read_certificate_status
2020-02-17 16:31:59.467305 +0800 putong boringssl_context_info_handler(1982) [C7.1:2][0x10b98a3d0] Client handshake state: TLS client verify_server_certificate
2020-02-17 16:31:59.467360 +0800 putong boringssl_context_copy_peer_sct_list(1002) [C7.1:2][0x10b98a3d0] SSL_get0_signed_cert_timestamp_list returned no SCT extension data
2020-02-17 16:31:59.467372 +0800 putong boringssl_helper_create_sec_trust_with_certificates(621) [C7.1:2][0x10b98a3d0] No TLS-provided SCTs
2020-02-17 16:31:59.467372 +0800 putong boringssl_helper_create_sec_trust_with_certificates(614) [C7.1:2][0x10b98a3d0] No TLS-provided OCSP response
2020-02-17 16:31:59.467372 +0800 putong boringssl_helper_create_sec_trust_with_certificates(607) [C7.1:2][0x10b98a3d0] SecTrustCreateWithCertificates result: 0
2020-02-17 16:31:59.467395 +0800 putong boringssl_context_certificate_verify_callback(2070) [C7.1:2][0x10b98a3d0] Asyncing for verify block
2020-02-17 16:31:59.467396 +0800 putong boringssl_session_handshake_incomplete(191) [C7.1:2][0x10b98a3d0] Early handshake return caused by SSL_ERROR_WANT_CERTIFICATE_VERIFY [16]
2020-02-17 16:31:59.467401 +0800 putong Connection 7: asked to evaluate TLS Trust
2020-02-17 16:31:59.470172 +0800 putong Task <A51E864E-0631-48D3-AA6C-A7D3BC22940A>.<3> auth completion disp=0 cred=0x283d6d090
2020-02-17 16:31:59.473304 +0800 trustd Failed to read from permanent storage at '/Library/Keychains/com.apple.security.exception_reset_counter.plist' or the data is bad. Defaulting to value 0.
2020-02-17 16:31:59.473349 +0800 putong Connection 7: TLS Trust result 0
2020-02-17 16:31:59.473356 +0800 putong boringssl_context_certificate_verify_callback_block_invoke_3(2079) [C7.1:2][0x10b98a3d0] Returning from verify block
2020-02-17 16:31:59.473357 +0800 putong boringssl_context_certificate_verify_callback(2046) [C7.1:2][0x10b98a3d0] Setting trust result to ssl_verify_ok
2020-02-17 16:31:59.473359 +0800 putong boringssl_context_info_handler(1982) [C7.1:2][0x10b98a3d0] Client handshake state: TLS client read_server_key_exchange
2020-02-17 16:31:59.473361 +0800 putong boringssl_context_message_handler(2257) [C7.1:2][0x10b98a3d0] Reading SSL3_RT_HANDSHAKE 333 bytes
2020-02-17 16:31:59.473490 +0800 putong boringssl_context_info_handler(1982) [C7.1:2][0x10b98a3d0] Client handshake state: TLS client read_certificate_request
2020-02-17 16:31:59.473494 +0800 putong boringssl_context_message_handler(2257) [C7.1:2][0x10b98a3d0] Reading SSL3_RT_HANDSHAKE 4 bytes
2020-02-17 16:31:59.473495 +0800 putong boringssl_context_info_handler(1982) [C7.1:2][0x10b98a3d0] Client handshake state: TLS client read_server_hello_done
2020-02-17 16:31:59.473495 +0800 putong boringssl_context_info_handler(1982) [C7.1:2][0x10b98a3d0] Client handshake state: TLS client send_client_certificate
2020-02-17 16:31:59.473496 +0800 putong boringssl_context_add_handshake_message_pending(577) [C7.1:2][0x10b98a3d0] Adding message(14)
2020-02-17 16:31:59.473498 +0800 putong boringssl_context_info_handler(1982) [C7.1:2][0x10b98a3d0] Client handshake state: TLS client send_client_key_exchange
2020-02-17 16:31:59.473856 +0800 putong boringssl_context_message_handler(2257) [C7.1:2][0x10b98a3d0] Writing SSL3_RT_HANDSHAKE 70 bytes
2020-02-17 16:31:59.473869 +0800 putong boringssl_context_info_handler(1982) [C7.1:2][0x10b98a3d0] Client handshake state: TLS client send_client_finished
2020-02-17 16:31:59.473869 +0800 putong boringssl_context_info_handler(1982) [C7.1:2][0x10b98a3d0] Client handshake state: TLS client send_client_certificate_verify
2020-02-17 16:31:59.473870 +0800 putong boringssl_context_message_handler(2257) [C7.1:2][0x10b98a3d0] Writing SSL3_RT_CHANGE_CIPHER_SPEC 1 bytes
2020-02-17 16:31:59.473917 +0800 putong boringssl_context_message_handler(2257) [C7.1:2][0x10b98a3d0] Writing SSL3_RT_HANDSHAKE 16 bytes
2020-02-17 16:31:59.473927 +0800 putong boringssl_context_info_handler(1982) [C7.1:2][0x10b98a3d0] Client handshake state: TLS client finish_flight
2020-02-17 16:31:59.474016 +0800 putong boringssl_context_info_handler(1982) [C7.1:2][0x10b98a3d0] Client handshake state: TLS client read_session_ticket
2020-02-17 16:31:59.474025 +0800 putong boringssl_context_info_handler(1982) [C7.1:2][0x10b98a3d0] Client handshake state: TLS client process_change_cipher_spec
2020-02-17 16:31:59.474026 +0800 putong boringssl_session_handshake_incomplete(191) [C7.1:2][0x10b98a3d0] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.474028 +0800 putong boringssl_session_handshake_incomplete(191) [C7.1:2][0x10b98a3d0] Early handshake return caused by SSL_ERROR_WANT_READ [2]
2020-02-17 16:31:59.474078 +0800 putong boringssl_context_message_handler(2257) [C8.1:2][0x10b98ac20] Reading SSL3_RT_HANDSHAKE 108 bytes
2020-02-17 16:31:59.474083 +0800 putong boringssl_context_info_handler(1982) [C8.1:2][0x10b98ac20] Client handshake state: TLS client read_server_certificate
2020-02-17 16:31:59.474085 +0800 putong boringssl_context_add_handshake_message_pending(577) [C8.1:2][0x10b98ac20] Adding message(2)
2020-02-17 16:31:59.474086 +0800 putong boringssl_context_message_handler(2257) [C8.1:2][0x10b98ac20] Reading SSL3_RT_HANDSHAKE 4911 bytes
2020-02-17 16:31:59.474093 +0800 putong boringssl_context_info_handler(1982) [C8.1:2][0x10b98ac20] Client handshake state: TLS client read_certificate_status
2020-02-17 16:31:59.474095 +0800 putong boringssl_context_info_handler(1982) [C8.1:2][0x10b98ac20] Client handshake state: TLS client verify_server_certificate
2020-02-17 16:31:59.474153 +0800 putong boringssl_context_copy_peer_sct_list(1002) [C8.1:2][0x10b98ac20] SSL_get0_signed_cert_timestamp_list returned no SCT extension data
2020-02-17 16:31:59.474164 +0800 putong boringssl_helper_create_sec_trust_with_certificates(621) [C8.1:2][0x10b98ac20] No TLS-provided SCTs
2020-02-17 16:31:59.474164 +0800 putong boringssl_helper_create_sec_trust_with_certificates(614) [C8.1:2][0x10b98ac20] No TLS-provided OCSP response
2020-02-17 16:31:59.474164 +0800 putong boringssl_helper_create_sec_trust_with_certificates(607) [C8.1:2][0x10b98ac20] SecTrustCreateWithCertificates result: 0
2020-02-17 16:31:59.474191 +0800 putong boringssl_context_certificate_verify_callback(2070) [C8.1:2][0x10b98ac20] Asyncing for verify block
2020-02-17 16:31:59.474193 +0800 putong boringssl_session_handshake_incomplete(191) [C8.1:2][0x10b98ac20] Early handshake return caused by SSL_ERROR_WANT_CERTIFICATE_VERIFY [16]
2020-02-17 16:31:59.474196 +0800 putong boringssl_session_handshake_incomplete(191) [C8.1:2][0x10b98ac20] Early handshake return caused by SSL_ERROR_WANT_CERTIFICATE_VERIFY [16]
2020-02-17 16:31:59.474196 +0800 putong boringssl_context_certificate_verify_callback(2039) [C8.1:2][0x10b98ac20] Verification already in progress.
2020-02-17 16:31:59.474198 +0800 putong boringssl_session_handshake_incomplete(191) [C8.1:2][0x10b98ac20] Early handshake return caused by SSL_ERROR_WANT_CERTIFICATE_VERIFY [16]
2020-02-17 16:31:59.474198 +0800 putong boringssl_context_certificate_verify_callback(2039) [C8.1:2][0x10b98ac20] Verification already in progress.
2020-02-17 16:31:59.474199 +0800 putong Connection 8: asked to evaluate TLS Trust
2020-02-17 16:31:59.474397 +0800 filecoordinationd Claim 772E9D0C-CCFE-4754-A337-52D9D785249A was revoked
2020-02-17 16:31:59.474451 +0800 putong PURLogFileManagerDefault: Critical error while creating log file: Error Domain=NSCocoaErrorDomain Code=512 "The operation couldn’t be completed." UserInfo={NSUserStringVariant=Folder}

FYI, I rejected your post that contains a link to the sysdiagnose log. Such logs can contain a wide variety of sensitive info and, while they’re super useful for debugging problems coming in from the field, it’s best not to post them in a public place.

As to what you can do with your sysdiagnose log, you should unpack it and open the

system_logs.logarchive
in Console app. Then start looking for log entries immediately before the failure. A good way to do this is to have your app log to the system log when it sees this error, so that you can locate the exact point in time where it shows up, and then work back from there.

Share and Enjoy

Quinn “The Eskimo!”
Apple Developer Relations, Developer Technical Support, Core OS/Hardware

let myEmail = "eskimo" + "1" + "@apple.com"

HI:

I post the logs, but I cant see any useful message for me. So any ideas? Or need more infomation.

Waiting for your reply, thanks.

Most of the stuff in the log you posted is networking related. The only thing file related is:

2020-02-17 16:31:59.474397 +0800 filecoordinationd Claim 772E9D0C-CCFE-4754-A337-52D9D785249A was revoked

AFAIK the API you’re calling isn’t coordinated. Are you doing this coordination yourself using

NSFileCoordinator
?

Also, earlier you wrote:

App cant save file to sandbox, including library document temp caches directory

It’s not clear from that what directory you’re trying to write to here. Please elaborate.

Share and Enjoy

Quinn “The Eskimo!”
Apple Developer Relations, Developer Technical Support, Core OS/Hardware

let myEmail = "eskimo" + "1" + "@apple.com"

HI:

I didnt use NSFileCoordinator class directlity. After search the source code, I only see the Google Firebase has the code calls.

Other failled logs between the context not contains the call of NSFileCoordinator. But the call of openudid's clicpboard operations.

My test code write files to below directories:

[NSSearchPathForDirectoriesInDomains(NSLibraryDirectory, NSUserDomainMask, YES) firstObject];
[NSSearchPathForDirectoriesInDomains(NSDocumentDirectory, NSUserDomainMask, YES) firstObject];
[NSSearchPathForDirectoriesInDomains(NSCachesDirectory, NSUserDomainMask, YES) firstObject];
NSTemporaryDirectory();

File name generated by uuid for each directories:

NSString *uuid = [[NSUUID UUID] UUIDString];

And write a small string to these files:

NSString *file = [direcotry stringByAppendingPathComponent:uuid];
NSError *error = nil;
[@"test" writeToFile:file atomically:YES encoding:NSUTF8StringEncoding error:&error];

Then I see the error as the post. It means I cant create file.

But there is my database file exists. I guess it sync by iCloud. and the it can be edited.eg: insert update etc.

or can I upload the logfile. And you can search the keyword PURLogFileManagerDefault to see the error context. may it helps?

https://www.dropbox.com/s/xmmsj9lde2u4c6w/system_logs.logarchive.zip?dl=0

Yeah, I got nothing )-: My recommendation is that you open a DTS tech support incident and discuss it with one of DTS’s file system experts.

Share and Enjoy

Quinn “The Eskimo!”
Apple Developer Relations, Developer Technical Support, Core OS/Hardware

let myEmail = "eskimo" + "1" + "@apple.com"

OK, I will try to contact, Thanks a lot!

May I add your wei xin(fang zhi he xie)? my wei xin is rock_homeboy and my dian hua hao ma is 18616309756, Im a RD of ByteDance(Douyin), and I have encountered the same problem as you mentioned above, currently contacting the user so that I can provide disk and system log diagnosis to Apple.


Let me describe the problem:

1.Failed to create file through NSFileManager function

- (BOOL)createFileAtPath:(NSString *)path contents:(nullable NSData *)data attributes:(nullable NSDictionary<nsfileattributekey, id=""> *)attr;


The error information obtained by printing errno and strerror (errno) is as follows:

errorCode = 17, errorDesc = File exists.


The following key file attributes are provided:

{
    NSFileCreationDate = "1970-01-01 00:00:02 +0000";
    NSFilePosixPermissions = 493;
    NSFileSystemNumber = 16777222;
    NSFileType = NSFileTypeDirectory;
}

2.Can't write to file using NSData

- (BOOL)writeToFile:(NSString *)path options:(NSDataWritingOptions)writeOptionsMask error:(NSError **)errorPtr;
error: Error Domain=NSCocoaErrorDomain Code=512 "wei neng cun chu gai wen jian" UserInfo={NSUserStringVariant=Folder}
  • I have found a way to solve it and if someone else has the same problem:

    1000-limit-error is not the same error as @logicat encountered, the problem seems to be that when iOS atomic write to a file, system first create a temporary file and then write data to it, and if the temporary file is accidentally interrupted while writing.

    For example, [MLModel compileModelAtURL] will temporarily create XXXX /Temp/(A Document Being Saved By yourApp)/***.mlmodelc when it is accidentally interrupted, (A Document Being Saved By ***) - temporary files will not be deleted, causing all atomic writes to fail, even if you restart your app.

    Try the following solve it(Language: Objective-C):

    1.Use nonatomic write, e.g.

    [NSData writeToFile:path options:0 error:&error]; // No temporary file, nonatomic

    [NSData writeToFile:path atomically:NO];

    [NSString writeToFile:path atomically:NO encoding:enc error:&error];

    [NSDictionary writeToURL:url atomically:NO];

    2.To solve the problem completely, you need to remove the temporary file from the problem folder, which is a hidden file like ***/(A Document Being Saved By yourApp)/xxxx

    So I restore the atomic write ability after I clear the temporary file or temporary folder(Note: Do not delete some files generated by the system).

    Hope the above tips help you.

Add a Comment

I'm also experiencing a similar issue. One user (out of thousands) is getting a 512 error – NSFileWriteUnknownError when the iOS app attempts to write a file to the caches directory or the documents directory.
The user is on iOS 13.3, and logging the error shows Error Domain=NSCocoaErrorDomain Code=512 "The file couldn’t be saved." UserInfo={NSUserStringVariant=Folder}

Having the exact same problem.


@logicat Did you ever find a root cause or fix besides deleting & reinstalling your app?


  • Can't create any new files.
  • The error message is "The file couldn't be saved." and there is no underlying error in the NSError instance.
  • errno == 17 after the write failure.
  • The file does not actually exist, nor are there any *.tmp.****** files present in the same parent directory.
  • Affects a very small segment of my user base, but that number is growing.
  • In my case, I only have reports for iOS 13+.
  • Offloading the app *does not* fix the problem
  • Deleting & reinstalling the app fixes the problem, but is obviously undesirable.
We have encountered the same exact issue. We've found that we can save a file to other directories like the documents directory but CANNOT save to the caches directory for a specific user.

We kept getting the 512 as well.
@logicat I have the same problem as you. Have you found the reason
@logicat We are running into exact same issue. I was able to obtain the device from my user with an installed copy of our app, however it's an iPad 2 running iOS 9, so sysdiagnose is unavailable as I believe. Console log shows nothing helpful except my error messages. Doing some investigation, I was able to check that underlying error of a [NSData writeToFile:options:error] call is non-existent. I have Firebase (no idea where it's trying to save the file) and CocoaLumberjack logging (trying to save file at Library/Caches) both failing to save the file. Playing with time profiler here are the results of trying to create a new log file for CocoaLumberjack (if it might be helpfull to someone):
Code Block
1.04 s 48.9% 0 s -[NSData(NSData) writeToFile:options:error:]
1.04 s 48.9% 0 s _NSWriteDataToFileWithExtendedAttributes
1.03 s 48.8% 0 s _NSCreateTemporaryFile_Protected
1.03 s 48.8% 1.00 ms -[NSFileManager _URLForReplacingItemAtURL:error:]
679.00 ms 32.0% 0 s 49-[NSFileManager _URLForReplacingItemAtURL:error:]_block_invoke
640.00 ms 30.2% 640.00 ms mkdir
38.00 ms 1.7% 1.00 ms -[NSURL(NSURL) fileSystemRepresentation]
12.00 ms 0.5% 0 s malloc_zone_malloc
12.00 ms 0.5% 0 s +[NSData(NSData) dataWithBytesNoCopy:length:]
10.00 ms 0.4% 1.00 ms CFURLGetFileSystemRepresentation
1.00 ms 0.0% 0 s objc_object::rootAutorelease2()
1.00 ms 0.0% 0 s -[NSURL(NSURL) _cfurl]
1.00 ms 0.0% 1.00 ms NSAllocateCollectable
1.00 ms 0.0% 1.00 ms objc_msgSend
188.00 ms 8.8% 1.00 ms -[NSString initWithFormat:]
90.00 ms 4.2% 2.00 ms +[NSURL(NSURL) fileURLWithPath:isDirectory:]
33.00 ms 1.5% 2.00 ms -[NSString(NSPathUtilities) stringByAppendingPathComponent:]
19.00 ms 0.8% 0 s -[NSBundle localizedStringForKey:value:table:]
12.00 ms 0.5% 2.00 ms CFRelease
3.00 ms 0.1% 0 s NSTemporaryDirectory
2.00 ms 0.0% 2.00 ms objc_object::rootAutorelease2()
2.00 ms 0.0% 0 s -[NSURL getResourceValue:forKey:error:]
1.00 ms 0.0% 1.00 ms -[NSCFString release]
1.00 ms 0.0% 1.00 ms -[__NSCFConstantString autorelease]
1.00 ms 0.0% 1.00 ms +[NSString allocWithZone:]
1.00 ms 0.0% 1.00 ms _Block_object_dispose
1.00 ms 0.0% 1.00 ms -[NSObject autorelease]
1.00 ms 0.0% 1.00 ms +[NSObject alloc]
1.00 ms 0.0% 1.00 ms lstat

However with all that, I have no clue what causes the issue. Were you able to resolve it?