rdar://26843578: CFNetwork asserts when NSURLSession receives HTTP/2 trailers

CFNetwork asserts when NSURLSession receives HTTP/2 trailers

Originator:	jcanizales
Number:	rdar://26843578	Date Originated:	16-Jun-2016 12:09 PM
Status:	Open	Resolved:
Product:	iOS SDK	Product Version:	iOS 10.0-beta (14A5261u), and 9.3
Classification:	Crash	Reproducible:	Always

 
Summary:
In the context of an HTTP/2 response, when the TCP packet with trailers arrives, CFNetwork asserts. Previous packets carrying headers and data are correctly processed and passed to the NSURLSession delegate. If the last packet carried an HTTP/2 data frame in addition to the trailers, that data isn't delivered before the assert.

This is verified to happen in iOS SDK versions 9.3 and 10-beta, and OS X SDK 10.11.5. Using both XCode 7.3.1 and XCode 8-beta. And both from Objective-C, Swift 2.2 (NSURLSession), and Swift 3 (URLSession).

Steps to Reproduce:
(In Swift 3 syntax, iOS 8-beta)

import UIKit

let session = URLSession(configuration: URLSessionConfiguration.default())

// Construct a request to an HTTP/2 server that returns trailers:

let url = URL(string: "https://grpc-test.sandbox.googleapis.com/grpc.testing.TestService/EmptyCall")!
var request = URLRequest(url: url)
// That specific server would return a 404 if we didn't set these:
request.httpMethod = "POST"
request.addValue("application/grpc", forHTTPHeaderField: "content-type")

let requestData = Data(bytes: [0, 0, 0, 0, 0])


// Execute request:

session.uploadTask(with: request, from: requestData) { (data, response, error) in
  print("CFNetwork asserts before this is executed.")
}.resume()


If instead of a callback you use a delegate, you can see that for longer responses (spanning multiple TCP packets) the headers and part of the response data are delivered before the assert.

Expected Results:
No assert.

Actual Results:
Assertion failed: (!fHeadersBegan),
function _onqueue_beginHeaders,
file /BuildRoot/Library/Caches/com.apple.xbs/Sources/CFNetwork_Sim/CFNetwork-790.2/HTTP2/HTTP2Stream.cpp,
line 731.

(Backtrace of all threads and full log output follows).

Backtrace of all threads:

  thread #1: tid = 0x4acbd1, 0x000000010acb2f72 libsystem_kernel.dylib`mach_msg_trap + 10, queue = 'com.apple.main-thread'
    frame #0: 0x000000010acb2f72 libsystem_kernel.dylib`mach_msg_trap + 10
    frame #1: 0x000000010acb23b3 libsystem_kernel.dylib`mach_msg + 55
    frame #2: 0x00000001075f6e84 CoreFoundation`__CFRunLoopServiceMachPort + 212
    frame #3: 0x00000001075f6301 CoreFoundation`__CFRunLoopRun + 1345
    frame #4: 0x00000001075f5b5d CoreFoundation`CFRunLoopRunSpecific + 285
    frame #5: 0x000000010c9dea48 GraphicsServices`GSEventRunModal + 161
    frame #6: 0x000000010802ee8b UIKit`UIApplicationMain + 159
    frame #7: 0x00000001074d108f iOSgRPCSwiftTester`main + 111 at AppDelegate.swift:12
    frame #8: 0x000000010a95f6bd libdyld.dylib`start + 1

  thread #2: tid = 0x4acca1, 0x000000010acb95e2 libsystem_kernel.dylib`__workq_kernreturn + 10
    frame #0: 0x000000010acb95e2 libsystem_kernel.dylib`__workq_kernreturn + 10
    frame #1: 0x000000010add6578 libsystem_pthread.dylib`_pthread_wqthread + 1283
    frame #2: 0x000000010add4341 libsystem_pthread.dylib`start_wqthread + 13

* thread #3: tid = 0x4acca2, 0x000000010acb8f06 libsystem_kernel.dylib`__pthread_kill + 10, queue = 'com.apple.CFNetwork.HTTP2.HTTP2Stream', stop reason = signal SIGABRT
  * frame #0: 0x000000010acb8f06 libsystem_kernel.dylib`__pthread_kill + 10
    frame #1: 0x000000010add94ec libsystem_pthread.dylib`pthread_kill + 90
    frame #2: 0x000000010aa0b0b3 libsystem_c.dylib`abort + 129
    frame #3: 0x000000010a9d2b51 libsystem_c.dylib`__assert_rtn + 320
    frame #4: 0x000000010b6b0956 CFNetwork`HTTP2Stream::_onqueue_beginHeaders() + 136
    frame #5: 0x000000010a8dd1e8 libdispatch.dylib`_dispatch_call_block_and_release + 12
    frame #6: 0x000000010a909dee libdispatch.dylib`_dispatch_client_callout + 8
    frame #7: 0x000000010a8e4a1d libdispatch.dylib`_dispatch_queue_serial_drain + 239
    frame #8: 0x000000010a8e579f libdispatch.dylib`_dispatch_queue_invoke + 1162
    frame #9: 0x000000010a8e7ee7 libdispatch.dylib`_dispatch_root_queue_drain + 719
    frame #10: 0x000000010a8e7bbc libdispatch.dylib`_dispatch_worker_thread3 + 123
    frame #11: 0x000000010add64de libsystem_pthread.dylib`_pthread_wqthread + 1129
    frame #12: 0x000000010add4341 libsystem_pthread.dylib`start_wqthread + 13

  thread #4: tid = 0x4acca3, 0x000000010acb9efa libsystem_kernel.dylib`kevent_qos + 10, queue = 'com.apple.libdispatch-manager'
    frame #0: 0x000000010acb9efa libsystem_kernel.dylib`kevent_qos + 10
    frame #1: 0x000000010a8fb4b0 libdispatch.dylib`_dispatch_mgr_wait_for_event + 79
    frame #2: 0x000000010a8f4f7a libdispatch.dylib`_dispatch_mgr_invoke + 248
    frame #3: 0x000000010a8f4d7c libdispatch.dylib`_dispatch_mgr_thread + 54

  thread #5: tid = 0x4acca4, 0x000000010acb913a libsystem_kernel.dylib`__sendmsg + 10, queue = 'com.apple.network.connections'
    frame #0: 0x000000010acb913a libsystem_kernel.dylib`__sendmsg + 10
    frame #1: 0x000000010be85afd libnetwork.dylib`__nw_socket_service_writes_block_invoke + 389
    frame #2: 0x000000010ab75685 libsystem_network.dylib`nw_frame_array_foreach + 60
    frame #3: 0x000000010be858f9 libnetwork.dylib`nw_socket_service_writes + 118
    frame #4: 0x000000010be8585a libnetwork.dylib`nw_socket_frame_output_finalizer + 114
    frame #5: 0x000000010be85da7 libnetwork.dylib`__nw_socket_finalize_output_frames_block_invoke + 39
    frame #6: 0x000000010ab7566c libsystem_network.dylib`nw_frame_array_foreach + 35
    frame #7: 0x000000010be820b1 libnetwork.dylib`nw_socket_finalize_output_frames + 94
    frame #8: 0x000000010bea6fb5 libnetwork.dylib`nw_coretls_callback_write + 988
    frame #9: 0x000000010bea8a92 libnetwork.dylib`__nw_coretls_service_writes_block_invoke + 99
    frame #10: 0x000000010ab75685 libsystem_network.dylib`nw_frame_array_foreach + 60
    frame #11: 0x000000010bea89ee libnetwork.dylib`nw_coretls_service_writes + 115
    frame #12: 0x000000010bea8f0f libnetwork.dylib`__nw_protocol_coretls_finalize_output_frames_block_invoke + 39
    frame #13: 0x000000010ab7566c libsystem_network.dylib`nw_frame_array_foreach + 35
    frame #14: 0x000000010bea5a42 libnetwork.dylib`nw_protocol_coretls_finalize_output_frames + 163
    frame #15: 0x000000010be63901 libnetwork.dylib`nw_endpoint_flow_service_writes + 2542
    frame #16: 0x000000010be62ccb libnetwork.dylib`nw_endpoint_handler_add_write_request + 194
    frame #17: 0x000000010be95c83 libnetwork.dylib`__nw_connection_write_multiple_block_invoke.243 + 38
    frame #18: 0x000000010a8dd1e8 libdispatch.dylib`_dispatch_call_block_and_release + 12
    frame #19: 0x000000010a909dee libdispatch.dylib`_dispatch_client_callout + 8
    frame #20: 0x000000010a8e4a1d libdispatch.dylib`_dispatch_queue_serial_drain + 239
    frame #21: 0x000000010a8e579f libdispatch.dylib`_dispatch_queue_invoke + 1162
    frame #22: 0x000000010a8e7ee7 libdispatch.dylib`_dispatch_root_queue_drain + 719
    frame #23: 0x000000010a8e7bbc libdispatch.dylib`_dispatch_worker_thread3 + 123
    frame #24: 0x000000010add64de libsystem_pthread.dylib`_pthread_wqthread + 1129
    frame #25: 0x000000010add4341 libsystem_pthread.dylib`start_wqthread + 13

  thread #6: tid = 0x4acca5, 0x000000010acb2f72 libsystem_kernel.dylib`mach_msg_trap + 10, name = 'com.apple.uikit.eventfetch-thread'
    frame #0: 0x000000010acb2f72 libsystem_kernel.dylib`mach_msg_trap + 10
    frame #1: 0x000000010acb23b3 libsystem_kernel.dylib`mach_msg + 55
    frame #2: 0x00000001075f6e84 CoreFoundation`__CFRunLoopServiceMachPort + 212
    frame #3: 0x00000001075f6301 CoreFoundation`__CFRunLoopRun + 1345
    frame #4: 0x00000001075f5b5d CoreFoundation`CFRunLoopRunSpecific + 285
    frame #5: 0x0000000107ab6cf0 Foundation`-[NSRunLoop(NSRunLoop) runMode:beforeDate:] + 274
    frame #6: 0x0000000107b3e721 Foundation`-[NSRunLoop(NSRunLoop) runUntilDate:] + 78
    frame #7: 0x0000000108a70312 UIKit`-[UIEventFetcher threadMain] + 118
    frame #8: 0x0000000107ac6cab Foundation`__NSThread__start__ + 1277
    frame #9: 0x000000010add699d libsystem_pthread.dylib`_pthread_body + 131
    frame #10: 0x000000010add691a libsystem_pthread.dylib`_pthread_start + 168
    frame #11: 0x000000010add4351 libsystem_pthread.dylib`thread_start + 13

  thread #7: tid = 0x4acca7, 0x000000010acb95e2 libsystem_kernel.dylib`__workq_kernreturn + 10
    frame #0: 0x000000010acb95e2 libsystem_kernel.dylib`__workq_kernreturn + 10
    frame #1: 0x000000010add6578 libsystem_pthread.dylib`_pthread_wqthread + 1283
    frame #2: 0x000000010add4341 libsystem_pthread.dylib`start_wqthread + 13

  thread #9: tid = 0x4accac, 0x000000010acb2fae libsystem_kernel.dylib`semaphore_wait_trap + 10, name = 'com.apple.NSURLConnectionLoader'
    frame #0: 0x000000010acb2fae libsystem_kernel.dylib`semaphore_wait_trap + 10
    frame #1: 0x000000010a9093fd libdispatch.dylib`_dispatch_thread_event_wait_slow + 16
    frame #2: 0x000000010a8e8c7b libdispatch.dylib`_dispatch_barrier_sync_f_slow + 353
    frame #3: 0x000000010b6aef81 CFNetwork`HTTP2Stream::copyProperty(MetaNetStreamInfo::ApplicableProperties, bool) + 125
    frame #4: 0x000000010b5bd395 CFNetwork`HTTPProtocol::handleStreamEvent(__CFHTTPMessage*, dispatch_data_s*, CFStreamError const*) + 87
    frame #5: 0x000000010b6b11c0 CFNetwork`HTTP2Stream::_onschedulingset_notifyDataAvailable(dispatch_data_s*) + 70
    frame #6: 0x000000010b6b1162 CFNetwork`___ZN11HTTP2Stream28_onqueue_notifyDataAvailableEv_block_invoke + 22
    frame #7: 0x000000010a909dee libdispatch.dylib`_dispatch_client_callout + 8
    frame #8: 0x000000010a8e123b libdispatch.dylib`_dispatch_block_invoke_direct + 567
    frame #9: 0x000000010b4da4c0 CFNetwork`RunloopBlockContext::_invoke_block(void const*, void*) + 24
    frame #10: 0x00000001075bd454 CoreFoundation`CFArrayApplyFunction + 68
    frame #11: 0x000000010b4da3b9 CFNetwork`RunloopBlockContext::perform() + 137
    frame #12: 0x000000010b4da250 CFNetwork`MultiplexerSource::perform() + 282
    frame #13: 0x000000010b4da072 CFNetwork`MultiplexerSource::_perform(void*) + 72
    frame #14: 0x0000000107611cb1 CoreFoundation`__CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE0_PERFORM_FUNCTION__ + 17
    frame #15: 0x00000001075f6c6c CoreFoundation`__CFRunLoopDoSources0 + 556
    frame #16: 0x00000001075f6156 CoreFoundation`__CFRunLoopRun + 918
    frame #17: 0x00000001075f5b5d CoreFoundation`CFRunLoopRunSpecific + 285
    frame #18: 0x000000010b4b71a8 CFNetwork`+[NSURLConnection(Loader) _resourceLoadLoop:] + 361
    frame #19: 0x0000000107ac6cab Foundation`__NSThread__start__ + 1277
    frame #20: 0x000000010add699d libsystem_pthread.dylib`_pthread_body + 131
    frame #21: 0x000000010add691a libsystem_pthread.dylib`_pthread_start + 168
    frame #22: 0x000000010add4351 libsystem_pthread.dylib`thread_start + 13

Full log output:

2016-06-16 11:47:07.853359 iOSgRPCSwiftTester[27652:4902053] bundleid: io.grpc.iOSgRPCSwiftTester, enable_level: 0, persist_level: 0, propagate_with_activity: 0
2016-06-16 11:47:07.854008 iOSgRPCSwiftTester[27652:4902053] subsystem: com.apple.UIKit, category: HIDEvents, enable_level: 0, persist_level: 0, default_ttl: 0, info_ttl: 0, debug_ttl: 0, generate_symptoms: 0, enable_oversize: 0, privacy_setting: 0
2016-06-16 11:47:07.854735 iOSgRPCSwiftTester[27652:4902049] Created DB, header sequence number = 256
2016-06-16 11:47:07.871268 iOSgRPCSwiftTester[27652:4902049] Created DB, header sequence number = 256
2016-06-16 11:47:07.885183 iOSgRPCSwiftTester[27652:4902049] subsystem: com.apple.BaseBoard, category: MachPort, enable_level: 0, persist_level: 0, default_ttl: 0, info_ttl: 0, debug_ttl: 0, generate_symptoms: 0, enable_oversize: 0, privacy_setting: 0
2016-06-16 11:47:07.902100 iOSgRPCSwiftTester[27652:4902052] subsystem: com.apple.FrontBoard, category: Common, enable_level: 0, persist_level: 0, default_ttl: 0, info_ttl: 0, debug_ttl: 0, generate_symptoms: 0, enable_oversize: 0, privacy_setting: 0
2016-06-16 11:47:07.965777 iOSgRPCSwiftTester[27652:4902049] subsystem: com.apple.network, category: , enable_level: 0, persist_level: 0, default_ttl: 0, info_ttl: 0, debug_ttl: 0, generate_symptoms: 0, enable_oversize: 0, privacy_setting: 0
2016-06-16 11:47:07.966533 iOSgRPCSwiftTester[27652:4902052] [] nw_endpoint_handler_start [1 grpc-test.sandbox.googleapis.com:443 initial path (null)]
2016-06-16 11:47:07.966851 iOSgRPCSwiftTester[27652:4902052] [] nw_connection_endpoint_report [1 grpc-test.sandbox.googleapis.com:443 initial path (null)] reported event path:start
2016-06-16 11:47:07.967814 iOSgRPCSwiftTester[27652:4902052] [] nw_connection_endpoint_report [1 grpc-test.sandbox.googleapis.com:443 waiting path (satisfied)] reported event path:satisfied
2016-06-16 11:47:07.968781 iOSgRPCSwiftTester[27652:4902052] subsystem: com.apple.SystemConfiguration, category: SCPreferences, enable_level: 0, persist_level: 0, default_ttl: 0, info_ttl: 0, debug_ttl: 0, generate_symptoms: 0, enable_oversize: 0, privacy_setting: 0
2016-06-16 11:47:07.970147 iOSgRPCSwiftTester[27652:4902052] [] nw_connection_endpoint_report [1 grpc-test.sandbox.googleapis.com:443 in_progress resolver (satisfied)] reported event resolver:start_dns
2016-06-16 11:47:07.996696 iOSgRPCSwiftTester[27652:4902050] [] nw_endpoint_resolver_update [1 grpc-test.sandbox.googleapis.com:443 in_progress resolver (satisfied)] Adding endpoint handler for 2607:f8b0:400e:c04::451.443
2016-06-16 11:47:07.997068 iOSgRPCSwiftTester[27652:4902050] [] nw_connection_endpoint_report [1 grpc-test.sandbox.googleapis.com:443 in_progress resolver (satisfied)] reported event resolver:receive_dns
2016-06-16 11:47:07.997367 iOSgRPCSwiftTester[27652:4902052] [] nw_host_stats_add_src recv too small, received 24, expected 28
2016-06-16 11:47:07.997660 iOSgRPCSwiftTester[27652:4902050] [] nw_endpoint_resolver_start_next_child [1 grpc-test.sandbox.googleapis.com:443 in_progress resolver (satisfied)] starting child endpoint 2607:f8b0:400e:c04::451.443
2016-06-16 11:47:07.997982 iOSgRPCSwiftTester[27652:4902052] [] nw_host_stats_add_src recv too small, received 24, expected 28
2016-06-16 11:47:07.998331 iOSgRPCSwiftTester[27652:4902050] [] nw_host_stats_add_src recv too small, received 24, expected 28
2016-06-16 11:47:07.998700 iOSgRPCSwiftTester[27652:4902050] [] nw_endpoint_resolver_start_next_child [1 grpc-test.sandbox.googleapis.com:443 in_progress resolver (satisfied)] starting next child endpoint in 250ms
2016-06-16 11:47:07.999054 iOSgRPCSwiftTester[27652:4902050] [] nw_endpoint_handler_start [1.1 2607:f8b0:400e:c04::451.443 initial path (null)]
2016-06-16 11:47:07.999464 iOSgRPCSwiftTester[27652:4902050] [] nw_connection_endpoint_report [1.1 2607:f8b0:400e:c04::451.443 initial path (null)] reported event path:start
2016-06-16 11:47:08.000172 iOSgRPCSwiftTester[27652:4902050] [] nw_connection_endpoint_report [1.1 2607:f8b0:400e:c04::451.443 waiting path (satisfied)] reported event path:satisfied
2016-06-16 11:47:08.000503 iOSgRPCSwiftTester[27652:4902050] [] __nwlog_err_simulate_crash_libsystem libsystem simulate crash unavailable, [libsystem_network.dylib: nw_endpoint_get_hostname :: incorrect endpoint type 1]
2016-06-16 11:47:08.001010 iOSgRPCSwiftTester[27652:4902050] [] nw_endpoint_get_hostname incorrect endpoint type 1, dumping backtrace:
        [x86_64] libnetcore-805.0.0.2.2
    0   libsystem_network.dylib             0x000000010ab8437f __nw_create_backtrace_string + 123
    1   libsystem_network.dylib             0x000000010ab8646e nw_endpoint_get_hostname + 75
    2   libnetwork.dylib                    0x000000010be69be7 nw_endpoint_proxy_handler_should_use_proxy + 125
    3   libnetwork.dylib                    0x000000010be7704f nw_endpoint_handler_path_change + 1509
    4   libnetwork.dylib                    0x000000010be768a2 nw_endpoint_handler_start + 570
    5   libnetwork.dylib                    0x000000010be8d026 nw_endpoint_resolver_start_next_child + 2050
    6   libdispatch.dylib                   0x000000010a8dd1e8 _dispatch_call_block_and_release + 12
    7   libdispatch.dylib                   0x000000010a909dee _dispatch_client_callout + 8
    8   libdispatch.dylib                   0x000000010a8e4a1d _dispatch_queue_serial_drain + 239
    9   libdi
2016-06-16 11:47:08.003163 iOSgRPCSwiftTester[27652:4902050] [] nw_connection_endpoint_report [1.1 2607:f8b0:400e:c04::451.443 in_progress socket-flow (satisfied)] reported event flow:start_connect
2016-06-16 11:47:08.003795 iOSgRPCSwiftTester[27652:4902050] [] nw_endpoint_resolver_update [1 grpc-test.sandbox.googleapis.com:443 in_progress resolver (satisfied)] Adding endpoint handler for 74.125.28.81:443
2016-06-16 11:47:08.004187 iOSgRPCSwiftTester[27652:4902050] [] nw_connection_endpoint_report [1 grpc-test.sandbox.googleapis.com:443 in_progress resolver (satisfied)] reported event resolver:receive_dns
2016-06-16 11:47:08.023838 iOSgRPCSwiftTester[27652:4902050] [] nw_endpoint_flow_protocol_connected [1.1 2607:f8b0:400e:c04::451.443 in_progress socket-flow (satisfied)] Output protocol connected
2016-06-16 11:47:08.024701 iOSgRPCSwiftTester[27652:4902050] [] nw_endpoint_flow_connected_path_change [1.1 2607:f8b0:400e:c04::451.443 ready socket-flow (satisfied)] Connected path is satisfied
2016-06-16 11:47:08.025035 iOSgRPCSwiftTester[27652:4902050] [] nw_connection_endpoint_report [1.1 2607:f8b0:400e:c04::451.443 ready socket-flow (satisfied)] reported event flow:finish_connect
2016-06-16 11:47:08.025449 iOSgRPCSwiftTester[27652:4902050] [] nw_connection_endpoint_report [1 grpc-test.sandbox.googleapis.com:443 ready resolver (satisfied)] reported event flow:finish_connect
2016-06-16 11:47:08.025974 iOSgRPCSwiftTester[27652:4902050] [] nw_connection_endpoint_report [1.1 2607:f8b0:400e:c04::451.443 ready socket-flow (satisfied)] reported event flow:changed_viability
2016-06-16 11:47:08.026642 iOSgRPCSwiftTester[27652:4902050] [] nw_connection_endpoint_report [1 grpc-test.sandbox.googleapis.com:443 ready resolver (satisfied)] reported event flow:changed_viability
2016-06-16 11:47:08.027336 iOSgRPCSwiftTester[27652:4902052] [] nw_endpoint_start_tls_while_connected [1.1 2607:f8b0:400e:c04::451.443 ready socket-flow (satisfied)]
2016-06-16 11:47:08.040593 iOSgRPCSwiftTester[27652:4902052] [] nw_connection_endpoint_report [1.1 2607:f8b0:400e:c04::451.443 in_progress socket-flow (satisfied)] reported event flow:start_secondary_connect
2016-06-16 11:47:08.041019 iOSgRPCSwiftTester[27652:4902052] [] nw_connection_endpoint_report [1 grpc-test.sandbox.googleapis.com:443 in_progress resolver (satisfied)] reported event flow:start_secondary_connect
2016-06-16 11:47:08.041432 iOSgRPCSwiftTester[27652:4902052] [] nw_connection_endpoint_report [1.1 2607:f8b0:400e:c04::451.443 in_progress socket-flow (satisfied)] reported event flow:start_connect
2016-06-16 11:47:08.041717 iOSgRPCSwiftTester[27652:4902052] [] nw_connection_endpoint_report [1 grpc-test.sandbox.googleapis.com:443 in_progress resolver (satisfied)] reported event flow:start_connect
2016-06-16 11:47:08.041991 iOSgRPCSwiftTester[27652:4902052] [] nw_endpoint_flow_protocol_connected [1.1 2607:f8b0:400e:c04::451.443 in_progress socket-flow (satisfied)] Transport protocol connected
2016-06-16 11:47:08.042406 iOSgRPCSwiftTester[27652:4902052] [] nw_connection_endpoint_report [1.1 2607:f8b0:400e:c04::451.443 in_progress socket-flow (satisfied)] reported event flow:finish_transport
2016-06-16 11:47:08.042710 iOSgRPCSwiftTester[27652:4902052] [] nw_connection_endpoint_report [1 grpc-test.sandbox.googleapis.com:443 in_progress resolver (satisfied)] reported event flow:finish_transport
2016-06-16 11:47:08.113542 iOSgRPCSwiftTester[27652:4902052] [] nw_endpoint_flow_protocol_connected [1.1 2607:f8b0:400e:c04::451.443 in_progress socket-flow (satisfied)] Output protocol connected
2016-06-16 11:47:08.114244 iOSgRPCSwiftTester[27652:4902052] [] nw_endpoint_flow_connected_path_change [1.1 2607:f8b0:400e:c04::451.443 ready socket-flow (satisfied)] Connected path is satisfied
2016-06-16 11:47:08.114498 iOSgRPCSwiftTester[27652:4902052] [] nw_connection_endpoint_report [1.1 2607:f8b0:400e:c04::451.443 ready socket-flow (satisfied)] reported event flow:finish_connect
2016-06-16 11:47:08.114776 iOSgRPCSwiftTester[27652:4902052] [] nw_connection_endpoint_report [1 grpc-test.sandbox.googleapis.com:443 ready resolver (satisfied)] reported event flow:finish_connect
Assertion failed: (!fHeadersBegan), function _onqueue_beginHeaders, file /BuildRoot/Library/Caches/com.apple.xbs/Sources/CFNetwork_Sim/CFNetwork-790.2/HTTP2/HTTP2Stream.cpp, line 731.

Comments

Since the upgrade to iOS 9.x to iOS 10.x https communication generates native tcp warnings and even crashes the ios app.
Within iOS 9.x, no native logging is shown and the https works as expected.

The network environment contains [app] => [load balancer] => [back-end]
The load balancer is a HAProxy configured with SSL/TLS offloading
https://www.haproxy.com/doc/aloha/7.0/deployment_guides/tls_layouts.html#ssl-tls-offloading

Console logging:
2016-10-11 15:32:36.737738 test-ios10-internet[369:38260] [] nw_socket_write_close shutdown(7, SHUT_WR): [57] Socket is not connected
2016-10-11 15:32:36.737830 test-ios10-internet[369:38260] [] nw_endpoint_flow_service_writes [1.1 172.27.6.77:443 ready socket-flow (satisfied)] Write request has 0 frame count, 0 byte count
2016-10-11 15:32:36.741152 test-ios10-internet[369:38260] [] _tcpconnection_write_eof_block_invoke Write close callback received error: [89] Operation canceled
2016-10-11 15:32:36.743560 test-ios10-internet[369:38260] downloadNSURLConnection_dataTaskWithRequest

When we configure the network environment without a load balancer: [app] => [back-end]
No native logging is shown and the https works as expected.

When we change the configuration of the load balancer to SSL/TLS passthrough: [app] => [load balancer] => [back-end]
* The load balancer is a HAProxy configured with SSL/TLS passthrough
https://www.haproxy.com/doc/aloha/7.0/deployment_guides/tls_layouts.html#ssl-tls-passthrough
No native logging is shown and the https works as expected.

Environment:
- iOS 10.0.2 with Xcode 8.0 (8A218a) writing in objective-C (Apple iPad Air and simulator)
- Centos 7.2.1511
- Haproxy: HA-Proxy version 1.5.14

Objective-C code: NSString *stringURL = @"https:///user.php"; - (void) test { NSURL URL = [NSURL URLWithString:stringURL]; NSMutableURLRequest urlRequest = [[NSMutableURLRequest alloc] initWithURL:URL];

    NSURLSession *session = [NSURLSession sharedSession];
    NSURLSessionDataTask *task = [session dataTaskWithRequest:urlRequest
                                            completionHandler:
                                  ^(NSData *data, NSURLResponse *response, NSError *error) {
                                      NSLog(@"downloadNSURLConnection_dataTaskWithRequest");
                                  }];
    [task resume];

}

By erwin.smeets at Oct. 11, 2016, 2:02 p.m. (reply...)

Hello, I am facing save issue on iOS 10, Xcode 8.0.

My Sample Code:

NSMutableURLRequest * urlRequest = [NSMutableURLRequest requestWithURL:url];
[urlRequest setHTTPMethod:@"POST"];
[urlRequest setHTTPBody:body];
[urlRequest setValue: @"application/soap+xml" forHTTPHeaderField:@"Content-Type"];
[urlRequest setValue: @"application/soap+xml" forHTTPHeaderField:@"Accept"];

NSURLSessionDataTask * dataTask = [defaultSession dataTaskWithRequest:urlRequest completionHandler:^(NSData *data1, NSURLResponse *response, NSError *error) {
        NSLog(@"Response:%@ %@\n", response, error);
        if(error == nil)
        {
             NSString * text = [[NSString alloc] initWithData: data1 encoding: NSUTF8StringEncoding];
              NSLog(@"Data = %@",text);
        }
}];

[dataTask resume];

Below is my app log: 2016-10-04 16:48:58.456224 TryXMLRequest[461:44648] [] nw_connection_read 1 Connection is not ready, sending error callback 2016-10-04 16:48:58.457140 TryXMLRequest[461:44661] [] nw_connection_write_close 1 Connection is not ready, sending error callback 2016-10-04 16:48:58.457874 TryXMLRequest[461:44648] [] _tcpconnection_write_eof_block_invoke Write close callback received error: [57] Socket is not connected 2016-10-04 16:49:05.052926 TryXMLRequest[461:44527] Response: { URL: http://10.107.2.153/onvif/device_service } { status code: 500, headers { } } (null)

Have you found any solution? Please let me know

Thanks,

By pandyanpunita at Oct. 4, 2016, 1:05 p.m. (reply...)

Please note: Reports posted here will not necessarily be seen by Apple. All problems should be submitted at bugreport.apple.com before they are posted here. Please only post information for Radars that you have filed yourself, and please do not include Apple confidential information in your posts. Thank you!

Open Radar

Community bug reports

CFNetwork asserts when NSURLSession receives HTTP/2 trailers

Comments