@@ -1381,7 +1381,7 @@ channel_collapse(channel_T *channel, int part)
13811381 * Returns OK or FAIL.
13821382 */
13831383 static int
1384- channel_save (channel_T * channel , int part , char_u * buf , int len )
1384+ channel_save (channel_T * channel , int part , char_u * buf , int len , char * lead )
13851385{
13861386 readq_T * node ;
13871387 readq_T * head = & channel -> ch_part [part ].ch_head ;
@@ -1422,9 +1422,9 @@ channel_save(channel_T *channel, int part, char_u *buf, int len)
14221422 head -> rq_prev -> rq_next = node ;
14231423 head -> rq_prev = node ;
14241424
1425- if (log_fd != NULL )
1425+ if (log_fd != NULL && lead != NULL )
14261426 {
1427- ch_log_lead ("RECV " , channel );
1427+ ch_log_lead (lead , channel );
14281428 fprintf (log_fd , "'" );
14291429 if (fwrite (buf , len , 1 , log_fd ) != 1 )
14301430 return FAIL ;
@@ -1434,7 +1434,7 @@ channel_save(channel_T *channel, int part, char_u *buf, int len)
14341434}
14351435
14361436/*
1437- * Use the read buffer of "channel"/"part" and parse a JSON messages that is
1437+ * Use the read buffer of "channel"/"part" and parse a JSON message that is
14381438 * complete. The messages are added to the queue.
14391439 * Return TRUE if there is more to read.
14401440 */
@@ -1444,7 +1444,9 @@ channel_parse_json(channel_T *channel, int part)
14441444 js_read_T reader ;
14451445 typval_T listtv ;
14461446 jsonq_T * item ;
1447- jsonq_T * head = & channel -> ch_part [part ].ch_json_head ;
1447+ chanpart_T * chanpart = & channel -> ch_part [part ];
1448+ jsonq_T * head = & chanpart -> ch_json_head ;
1449+ int status ;
14481450 int ret ;
14491451
14501452 if (channel_peek (channel , part ) == NULL )
@@ -1457,15 +1459,23 @@ channel_parse_json(channel_T *channel, int part)
14571459 reader .js_fill = NULL ;
14581460 /* reader.js_fill = channel_fill; */
14591461 reader .js_cookie = channel ;
1460- ret = json_decode (& reader , & listtv ,
1461- channel -> ch_part [part ].ch_mode == MODE_JS ? JSON_JS : 0 );
1462- if (ret == OK )
1462+
1463+ /* When a message is incomplete we wait for a short while for more to
1464+ * arrive. After the delay drop the input, otherwise a truncated string
1465+ * or list will make us hang. */
1466+ status = json_decode (& reader , & listtv ,
1467+ chanpart -> ch_mode == MODE_JS ? JSON_JS : 0 );
1468+ if (status == OK )
14631469 {
14641470 /* Only accept the response when it is a list with at least two
14651471 * items. */
14661472 if (listtv .v_type != VAR_LIST || listtv .vval .v_list -> lv_len < 2 )
14671473 {
1468- /* TODO: give error */
1474+ if (listtv .v_type != VAR_LIST )
1475+ ch_error (channel , "Did not receive a list, discarding" );
1476+ else
1477+ ch_errorn (channel , "Expected list with two items, got %d" ,
1478+ listtv .vval .v_list -> lv_len );
14691479 clear_tv (& listtv );
14701480 }
14711481 else
@@ -1496,13 +1506,70 @@ channel_parse_json(channel_T *channel, int part)
14961506 }
14971507 }
14981508
1499- /* Put the unread part back into the channel.
1500- * TODO: insert in front */
1501- if (reader . js_buf [ reader . js_used ] != NUL )
1509+ if ( status == OK )
1510+ chanpart -> ch_waiting = FALSE;
1511+ else if (status == MAYBE )
15021512 {
1513+ if (!chanpart -> ch_waiting )
1514+ {
1515+ /* First time encountering incomplete message, set a deadline of
1516+ * 100 msec. */
1517+ ch_log (channel , "Incomplete message - wait for more" );
1518+ reader .js_used = 0 ;
1519+ chanpart -> ch_waiting = TRUE;
1520+ #ifdef WIN32
1521+ chanpart -> ch_deadline = GetTickCount () + 100L ;
1522+ #else
1523+ gettimeofday (& chanpart -> ch_deadline , NULL );
1524+ chanpart -> ch_deadline .tv_usec += 100 * 1000 ;
1525+ if (chanpart -> ch_deadline .tv_usec > 1000 * 1000 )
1526+ {
1527+ chanpart -> ch_deadline .tv_usec -= 1000 * 1000 ;
1528+ ++ chanpart -> ch_deadline .tv_sec ;
1529+ }
1530+ #endif
1531+ }
1532+ else
1533+ {
1534+ int timeout ;
1535+ #ifdef WIN32
1536+ timeout = GetTickCount () > chanpart -> ch_deadline ;
1537+ #else
1538+ {
1539+ struct timeval now_tv ;
1540+
1541+ gettimeofday (& now_tv , NULL );
1542+ timeout = now_tv .tv_sec > chanpart -> ch_deadline .tv_sec
1543+ || (now_tv .tv_sec == chanpart -> ch_deadline .tv_sec
1544+ && now_tv .tv_usec > chanpart -> ch_deadline .tv_usec );
1545+ }
1546+ #endif
1547+ if (timeout )
1548+ {
1549+ status = FAIL ;
1550+ chanpart -> ch_waiting = FALSE;
1551+ }
1552+ else
1553+ {
1554+ reader .js_used = 0 ;
1555+ ch_log (channel , "still waiting on incomplete message" );
1556+ }
1557+ }
1558+ }
1559+
1560+ if (status == FAIL )
1561+ {
1562+ ch_error (channel , "Decoding failed - discarding input" );
1563+ ret = FALSE;
1564+ chanpart -> ch_waiting = FALSE;
1565+ }
1566+ else if (reader .js_buf [reader .js_used ] != NUL )
1567+ {
1568+ /* Put the unread part back into the channel.
1569+ * TODO: insert in front */
15031570 channel_save (channel , part , reader .js_buf + reader .js_used ,
1504- (int )(reader .js_end - reader .js_buf ) - reader .js_used );
1505- ret = TRUE;
1571+ (int )(reader .js_end - reader .js_buf ) - reader .js_used , NULL );
1572+ ret = status == MAYBE ? FALSE: TRUE;
15061573 }
15071574 else
15081575 ret = FALSE;
@@ -1570,6 +1637,8 @@ channel_get_json(channel_T *channel, int part, int id, typval_T **rettv)
15701637 || tv -> vval .v_number != channel -> ch_part [part ].ch_block_id )))
15711638 {
15721639 * rettv = item -> jq_value ;
1640+ if (tv -> v_type == VAR_NUMBER )
1641+ ch_logn (channel , "Getting JSON message %d" , tv -> vval .v_number );
15731642 remove_json_node (head , item );
15741643 return OK ;
15751644 }
@@ -1605,12 +1674,14 @@ channel_exe_cmd(channel_T *channel, int part, typval_T *argv)
16051674
16061675 if (STRCMP (cmd , "ex" ) == 0 )
16071676 {
1677+ ch_logs (channel , "Executing ex command '%s'" , (char * )arg );
16081678 do_cmdline_cmd (arg );
16091679 }
16101680 else if (STRCMP (cmd , "normal" ) == 0 )
16111681 {
16121682 exarg_T ea ;
16131683
1684+ ch_logs (channel , "Executing normal command '%s'" , (char * )arg );
16141685 ea .arg = arg ;
16151686 ea .addr_count = 0 ;
16161687 ea .forceit = TRUE; /* no mapping */
@@ -1620,6 +1691,7 @@ channel_exe_cmd(channel_T *channel, int part, typval_T *argv)
16201691 {
16211692 exarg_T ea ;
16221693
1694+ ch_log (channel , "redraw" );
16231695 ea .forceit = * arg != NUL ;
16241696 ex_redraw (& ea );
16251697 showruler (FALSE);
@@ -1661,11 +1733,18 @@ channel_exe_cmd(channel_T *channel, int part, typval_T *argv)
16611733 /* Don't pollute the display with errors. */
16621734 ++ emsg_skip ;
16631735 if (!is_call )
1736+ {
1737+ ch_logs (channel , "Evaluating expression '%s'" , (char * )arg );
16641738 tv = eval_expr (arg , NULL );
1665- else if (func_call (arg , & argv [2 ], NULL , NULL , & res_tv ) == OK )
1666- tv = & res_tv ;
1739+ }
16671740 else
1668- tv = NULL ;
1741+ {
1742+ ch_logs (channel , "Calling '%s'" , (char * )arg );
1743+ if (func_call (arg , & argv [2 ], NULL , NULL , & res_tv ) == OK )
1744+ tv = & res_tv ;
1745+ else
1746+ tv = NULL ;
1747+ }
16691748
16701749 if (argv [id_idx ].v_type == VAR_NUMBER )
16711750 {
@@ -1867,10 +1946,7 @@ may_invoke_callback(channel_T *channel, int part)
18671946
18681947 if (argv [0 ].v_type == VAR_STRING )
18691948 {
1870- char_u * cmd = argv [0 ].vval .v_string ;
1871-
18721949 /* ["cmd", arg] or ["cmd", arg, arg] or ["cmd", arg, arg, arg] */
1873- ch_logs (channel , "Executing %s command" , (char * )cmd );
18741950 channel_exe_cmd (channel , part , argv );
18751951 free_tv (listtv );
18761952 return TRUE;
@@ -2293,7 +2369,7 @@ channel_read(channel_T *channel, int part, char *func)
22932369 break ; /* error or nothing more to read */
22942370
22952371 /* Store the read message in the queue. */
2296- channel_save (channel , part , buf , len );
2372+ channel_save (channel , part , buf , len , "RECV " );
22972373 readlen += len ;
22982374 if (len < MAXMSGSIZE )
22992375 break ; /* did read everything that's available */
@@ -2320,7 +2396,7 @@ channel_read(channel_T *channel, int part, char *func)
23202396 if (channel -> ch_part [part ].ch_mode == MODE_RAW
23212397 || channel -> ch_part [part ].ch_mode == MODE_NL )
23222398 channel_save (channel , part , (char_u * )DETACH_MSG_RAW ,
2323- (int )STRLEN (DETACH_MSG_RAW ));
2399+ (int )STRLEN (DETACH_MSG_RAW ), "PUT " );
23242400
23252401 /* TODO: When reading from stdout is not possible, should we try to
23262402 * keep stdin and stderr open? Probably not, assume the other side
@@ -2365,9 +2441,13 @@ channel_read_block(channel_T *channel, int part, int timeout)
23652441 continue ;
23662442
23672443 /* Wait for up to the channel timeout. */
2368- if (fd == INVALID_FD
2369- || channel_wait (channel , fd , timeout ) == FAIL )
2444+ if (fd == INVALID_FD )
23702445 return NULL ;
2446+ if (channel_wait (channel , fd , timeout ) == FAIL )
2447+ {
2448+ ch_log (channel , "Timed out" );
2449+ return NULL ;
2450+ }
23712451 channel_read (channel , part , "channel_read_block" );
23722452 }
23732453
@@ -2407,24 +2487,26 @@ channel_read_block(channel_T *channel, int part, int timeout)
24072487channel_read_json_block (
24082488 channel_T * channel ,
24092489 int part ,
2410- int timeout ,
2490+ int timeout_arg ,
24112491 int id ,
24122492 typval_T * * rettv )
24132493{
24142494 int more ;
24152495 sock_T fd ;
2496+ int timeout ;
2497+ chanpart_T * chanpart = & channel -> ch_part [part ];
24162498
24172499 ch_log (channel , "Reading JSON" );
24182500 if (id != -1 )
2419- channel -> ch_part [ part ]. ch_block_id = id ;
2501+ chanpart -> ch_block_id = id ;
24202502 for (;;)
24212503 {
24222504 more = channel_parse_json (channel , part );
24232505
24242506 /* search for messsage "id" */
24252507 if (channel_get_json (channel , part , id , rettv ) == OK )
24262508 {
2427- channel -> ch_part [ part ]. ch_block_id = 0 ;
2509+ chanpart -> ch_block_id = 0 ;
24282510 return OK ;
24292511 }
24302512
@@ -2435,14 +2517,50 @@ channel_read_json_block(
24352517 if (channel_parse_messages ())
24362518 continue ;
24372519
2438- /* Wait for up to the timeout. */
2439- fd = channel -> ch_part [part ].ch_fd ;
2520+ /* Wait for up to the timeout. If there was an incomplete message
2521+ * use the deadline for that. */
2522+ timeout = timeout_arg ;
2523+ if (chanpart -> ch_waiting )
2524+ {
2525+ #ifdef WIN32
2526+ timeout = chanpart -> ch_deadline - GetTickCount () + 1 ;
2527+ #else
2528+ {
2529+ struct timeval now_tv ;
2530+
2531+ gettimeofday (& now_tv , NULL );
2532+ timeout = (chanpart -> ch_deadline .tv_sec
2533+ - now_tv .tv_sec ) * 1000
2534+ + (chanpart -> ch_deadline .tv_usec
2535+ - now_tv .tv_usec ) / 1000
2536+ + 1 ;
2537+ }
2538+ #endif
2539+ if (timeout < 0 )
2540+ {
2541+ /* Something went wrong, channel_parse_json() didn't
2542+ * discard message. Cancel waiting. */
2543+ chanpart -> ch_waiting = FALSE;
2544+ timeout = timeout_arg ;
2545+ }
2546+ else if (timeout > timeout_arg )
2547+ timeout = timeout_arg ;
2548+ }
2549+ fd = chanpart -> ch_fd ;
24402550 if (fd == INVALID_FD || channel_wait (channel , fd , timeout ) == FAIL )
2441- break ;
2442- channel_read (channel , part , "channel_read_json_block" );
2551+ {
2552+ if (timeout == timeout_arg )
2553+ {
2554+ if (fd != INVALID_FD )
2555+ ch_log (channel , "Timed out" );
2556+ break ;
2557+ }
2558+ }
2559+ else
2560+ channel_read (channel , part , "channel_read_json_block" );
24432561 }
24442562 }
2445- channel -> ch_part [ part ]. ch_block_id = 0 ;
2563+ chanpart -> ch_block_id = 0 ;
24462564 return FAIL ;
24472565}
24482566
0 commit comments